I wanna make sure why LOCATION UPDATE REQUEST is always faild

This is merely a historical archive of years 2008-2021, before the migration to mailman3.

A maintained and still updated list archive can be found at https://lists.osmocom.org/hyperkitty/list/baseband-devel@lists.osmocom.org/.

zhengfanf zhengfanf at hotmail.com
Wed Mar 9 15:53:53 UTC 2011 


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 
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.osmocom.org/pipermail/baseband-devel/attachments/20110309/e3a29411/attachment.htm>

More information about the baseband-devel mailing list