hello, when i run osmocom i meet a problem that LOCATION UPDATE REQUEST is always faild, the details are in the following:

1, my hardware environment: a Moto C118 mobile; a cheap RS232 com port to jack port data cable (unkown chip); a USB2 to RS232 converter using FTDI chip; i5 CPU with GIGABYTE motherbord running with Ubuntu 9.04;

2, i run the command osmocon, mobile, and telnet as below in seprate terminals in order. ./osmocon -p /dev/ttyUSB0 -m c123xor ../../target/firmware/board/compal_e88/layer1.compalram.bin ./mobile -i 127.0.0.1 telnet localhost 4247 en sim reader 1

3, after that osmocom is working, but things doesn't happed what i wish, LOCATION UPDATE REQUEST is always faild so that the phone can not make calls. -in command mobile running terminial i grubbed the following log:

" <0001> gsm48_rr.c:2006 PAGING ignored, we are not camping. writing msgb to gsmtap fd: Connection refused <0001> gsm48_rr.c:694 timer T3126 has fired <000d> gsm48_rr.c:699 Requesting channel failed <0001> gsm48_rr.c:363 new state connection pending -> idle <0003> gsm322.c:3318 (ms 1) Event 'EVENT_RET_IDLE' for Cell selection in state 'C3 camped normally' <0003> gsm322.c:2889 Selecting frequency 22. after LOC.UPD. <0003> gsm322.c:251 Sync to ARFCN=22 rxlev=-56 (Sysinfo, ccch mode NON-COMB) <0003> gsm322.c:540 new state 'C3 camped normally' -> 'C3 camped normally' <0004> gsm48_mm.c:3695 (ms 1) Received 'RR_REL_IND' from RR in state wait for RR connection (location updating) <0004> gsm48_mm.c:2589 RR link released after loc. upd. <000d> gsm48_mm.c:2533 Location update failed <000d> gsm48_mm.c:2543 Try location update later <0004> gsm48_mm.c:2545 Loc. upd. failed, retry #0 <0004> gsm48_mm.c:391 starting T3211 (loc. upd. retry delay) with 15.0 seconds <0004> gsm48_mm.c:4083 (ms 1) Received 'MM_EVENT_CELL_SELECTED' event in state wait for RR connection (location updating) <0004> gsm48_mm.c:1055 We are in registered LAI as returning to MM IDLE <0004> gsm48_mm.c:892 new state wait for RR connection (location updating) -> MM IDLE, normal service <0003> gsm322.c:2433 Channel synched. (ARFCN=22, snr=13, BSIC=10) <0001> gsm322.c:2460 using DSC of 90 <0003> gsm48_rr.c:4548 Channel provides data. writing msgb to gsmtap fd: Connection refused writing msgb to gsmtap fd: Connection refused <0001> gsm48_rr.c:609 MON: f=22 lev=-52 snr= 0 ber= 62 LAI=460 00 11a5 ID=629a writing msgb to gsmtap fd: Connection refused <0001> gsm48_rr.c:2265 IMMEDIATE ASSIGNMENT: <0001> gsm48_rr.c:2286 (ta 1/553m ra 0x7f chan_nr 0x0e ARFCN 22 TS 6 SS 0 TSC 2) <0001> gsm48_rr.c:2291 Not for us, no request. "

-it shows that LOCATION UPDATE REQUEST is faild and it will be retry, and use command "OsmocomBB# show ms" also can find that the mobile is trying hard to get location update successfully:

" OsmocomBB# show ms MS '1' is up, MM connection active IMEI: 000000000000000 IMEISV: 0000000000000000 IMEI generation: fixed automatic network selection state: A1 trying RPLMN cell selection state: C3 camped normally radio ressource layer state: connection pending mobility management layer state: wait for RR connection (location updating) OsmocomBB# show ms MS '1' is up, service is normal IMEI: 000000000000000 IMEISV: 0000000000000000 IMEI generation: fixed automatic network selection state: A1 trying RPLMN cell selection state: C3 camped normally (ARFCN 22) radio ressource layer state: idle mobility management layer state: MM idle, normal service OsmocomBB# show ms MS '1' is up, service is normal IMEI: 000000000000000 IMEISV: 0000000000000000 IMEI generation: fixed automatic network selection state: A1 trying RPLMN cell selection state: C3 camped normally (ARFCN 22) radio ressource layer state: idle mobility management layer state: MM idle, normal service OsmocomBB# show ms MS '1' is up, MM connection active IMEI: 000000000000000 IMEISV: 0000000000000000 IMEI generation: fixed automatic network selection state: A1 trying RPLMN cell selection state: C3 camped normally radio ressource layer state: connection pending mobility management layer state: wait for RR connection (location updating) "

-and in command osmocon terminal, i found the log may show the LOCATION UPDATE REQUEST faild reasons.

" Received PROMPT1 from phone, responding with CMD read_file(../../target/firmware/board/compal_e88/layer1.compalram.bin): file_size=53948, hdr_len=4, dnload_len=53955 got 1 bytes from modem, data looks like: 1b . got 1 bytes from modem, data looks like: f6 . got 1 bytes from modem, data looks like: 02 . got 1 bytes from modem, data looks like: 00 . got 1 bytes from modem, data looks like: 41 A got 1 bytes from modem, data looks like: 02 . got 1 bytes from modem, data looks like: 43 C Received PROMPT2 from phone, starting download handle_write(): 4096 bytes (4096/53955) handle_write(): 4096 bytes (8192/53955) handle_write(): 4096 bytes (12288/53955) handle_write(): 4096 bytes (16384/53955) handle_write(): 4096 bytes (20480/53955) handle_write(): 4096 bytes (24576/53955) handle_write(): 4096 bytes (28672/53955) handle_write(): 4096 bytes (32768/53955) handle_write(): 4096 bytes (36864/53955) handle_write(): 4096 bytes (40960/53955) handle_write(): 4096 bytes (45056/53955) handle_write(): 4096 bytes (49152/53955) handle_write(): 4096 bytes (53248/53955) handle_write(): 707 bytes (53955/53955) handle_write(): finished got 1 bytes from modem, data looks like: 1b . got 1 bytes from modem, data looks like: f6 . got 1 bytes from modem, data looks like: 02 . got 1 bytes from modem, data looks like: 00 . got 1 bytes from modem, data looks like: 41 A got 1 bytes from modem, data looks like: 03 . got 1 bytes from modem, data looks like: 42 B Received DOWNLOAD ACK from phone, your code is running now! OSMOCOM Layer 1 (revision osmocon_v0.0.0-757-gc4483bf-modified) ====================================================================== Device ID code: 0xb4fb Device Version code: 0x0000 ARM ID code: 0xfff3 cDSP ID code: 0x0128 Die ID code: 71c60b1d89021625 ====================================================================== REG_DPLL=0x2413 CNTL_ARM_CLK=0xf0a1 CNTL_CLK=0xff91 CNTL_RST=0xfff3 CNTL_ARM_DIV=0xfff9 ====================================================================== Power up simcard: THIS FIRMWARE WAS COMPILED WITHOUT TX SUPPORT!!! Assert DSP into Reset Releasing DSP from Reset Setting some dsp_api.ndb values Setting API NDB parameters DSP Download Status: 0x0001 DSP API Version: 0x0000 0x0000 Finishing download phase DSP Download Status: 0x0002 DSP API Version: 0x3606 0x0000 LOST 1634! "

" SB2 (2663816:2): TOA= 26, Power= -60dBm, Angle= 132Hz => SB 0x003cf629: BSIC=10 fn=1331917(1004/15/ 1)=> DSP reports SB in bit that is 965199799 bits in the future?!? Synchronize_TDMA => DSP reports FB in bit that is 965199776 bits in the future?!? LOST 1908! nb_cmd(0) and rxnb.msg != NULLL1CTL_PARAM_REQ (ta=0, tx_power=5) L1CTL_RACH_REQ (ra=0x0a, offset=8 combined=0) L1CTL_PARAM_REQ (ta=0, tx_power=5) L1CTL_RACH_REQ (ra=0x0a, offset=236 combined=0) L1CTL_PARAM_REQ (ta=0, tx_power=5) L1CTL_RACH_REQ (ra=0x0d, offset=248 combined=0) L1CTL_PARAM_REQ (ta=0, tx_power=5) L1CTL_RACH_REQ (ra=0x06, offset=240 combined=0) L1CTL_PARAM_REQ (ta=0, tx_power=5) L1CTL_RACH_REQ (ra=0x04, offset=217 combined=0) L1CTL_DM_REL_REQL1CTL_RESET_REQ: FULL!L1CTL_RESET_REQ: FULL!L1CTL_FBSB_REQ (arfcn=22, flags=0x7) Starting FCCH RecognitionEMPTY FB0 (1334018:5): TOA= 5040, Power= -57dBm, Angle= 2049Hz FB1 (1334028:8): TOA= 8755, Power= -57dBm, Angle= 223Hz fn_offset=1334026 (fn=1334028 + attempt=8 + ntdma = 6)m delay=8 (fn_offset=1334026 + 11 - fn=1334028 - 1 scheduling next FB/SB detection task with delay 8 =>FB @ FNR 1334026 fn_offset=1334026 qbits=4836 Synchronize_TDMA LOST 3717! SB1 (2668059:1): TOA= 27, Power= -59dBm, Angle= -9Hz => SB 0x0111f729: BSIC=10 fn=1334038(1006/ 4/31)=> DSP reports SB in bit that is 959894800 bits in the future?!? Synchronize_TDMA => DSP reports FB in bit that is 959894777 bits in the future?!? LOST 1909! nb_cmd(0) and rxnb.msg != NULLL1CTL_RESET_REQ: FULL!EMPTY L1CTL_FBSB_REQ (arfcn=22, flags=0x7) Starting FCCH RecognitionFB0 (1337271:8): TOA= 9312, Power= -56dBm, Angle=-3405Hz FB1 (1337282:9): TOA= 9999, Power= -56dBm, Angle= 5216Hz fn_offset=1337280 (fn=1337282 + attempt=9 + ntdma = 7)m delay=8 (fn_offset=1337280 + 11 - fn=1337282 - 1 scheduling next FB/SB detection task with delay 8 FB1 (1337302:11): TOA=12507, Power= -56dBm, Angle= 431Hz fn_offset=1337300 (fn=1337302 + attempt=11 + ntdma = 9)m delay=8 (fn_offset=1337300 + 11 - fn=1337302 - 1 scheduling next FB/SB detection task with delay 8 =>FB @ FNR 1337300 fn_offset=1337300 qbits=4844 Synchronize_TDMA LOST 3719! SB1 (2674604:1): TOA= 24, Power= -56dBm, Angle= 263Hz => SB 0x000af829: BSIC=10 fn=1337312(1008/ 2/41)=> DSP reports SB in bit that is 951713547 bits in the future?!? Synchronize_TDMA => DSP reports FB in bit that is 951713524 bits in the future?!? LOST 1905! nb_cmd(0) and rxnb.msg != NULLL1CTL_PARAM_REQ (ta=0, tx_power=5) L1CTL_RACH_REQ (ra=0x0f, offset=13 combined=0) L1CTL_PARAM_REQ (ta=0, tx_power=5) L1CTL_RACH_REQ (ra=0x0a, offset=233 combined=0) L1CTL_PARAM_REQ (ta=0, tx_power=5) L1CTL_RACH_REQ (ra=0x0a, offset=237 combined=0) L1CTL_PARAM_REQ (ta=0, tx_power=5) L1CTL_RACH_REQ (ra=0x0e, offset=240 combined=0) L1CTL_PARAM_REQ (ta=0, tx_power=5) L1CTL_RACH_REQ (ra=0x04, offset=241 combined=0) L1CTL_DM_REL_REQL1CTL_RESET_REQ: FULL!L1CTL_RESET_REQ: FULL!L1CTL_FBSB_REQ (arfcn=22, flags=0x7) Starting FCCH RecognitionFB0 (1339424:4): TOA= 3792, Power= -53dBm, Angle= 2044Hz FB1 (1339434:8): TOA= 8755, Power= -52dBm, Angle= 295Hz fn_offset=1339432 (fn=1339434 + attempt=8 + ntdma = 6)m delay=8 (fn_offset=1339432 + 11 - fn=1339434 - 1 scheduling next FB/SB detection task with delay 8 =>FB @ FNR 1339432 fn_offset=1339432 qbits=4836 Synchronize_TDMA LOST 3717! "

-i found the value of LOST is too big, and i tried to look for reasons in codes and found function "check_lost_frame()" below (in sync.c, lines 180 to 205). After read this code, i think it's delays of physical layer caused so so much LOST value.

" /* Lost TDMA interrupt detection. This works by starting a hardware timer * that is clocked by the same master clock source (VCTCXO). We expect * 1875 timer ticks in the duration of a TDMA frame (5000 qbits / 1250 bits) */ /* Timer for detecting lost IRQ */ #define TIMER_TICKS_PER_TDMA 1875 #define TIMER_TICK_JITTER 1 static int last_timestamp; static inline void check_lost_frame(void) { int diff, timestamp = hwtimer_read(1); if (last_timestamp < timestamp) last_timestamp += (4*TIMER_TICKS_PER_TDMA); diff = last_timestamp - timestamp; /* allow for a bit of jitter */ if (diff < TIMER_TICKS_PER_TDMA - TIMER_TICK_JITTER || diff > TIMER_TICKS_PER_TDMA + TIMER_TICK_JITTER) printf("LOST %d!\n", diff); last_timestamp = timestamp; } "

4, here, i want some help to figure out whether physical delays caused big LOST value, and big LOST value caused LOCATION UPDATE REQUEST failed? if it's the problem of the physical layer, i want to make sure which part should be held responsible: -is that the cheap RS232 com port to jack port data cable caused the delays? -or is the USB2 to RS232 converter caused the delays? -or is that some bugs in layer1.compalram.bin caused the delays? i really want some experienced engineer to help me fix up the problem.

Thanks! Best Regards! zheng

2011-03-09