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
