OsmocomBB Mobile Call Setup Weird behaviour

classic Classic list List threaded Threaded
3 messages Options
Reply | Threaded
Open this post in threaded view
|

OsmocomBB Mobile Call Setup Weird behaviour

dagar
OK am testing the mobile app with C123 using real sim but getting some odd behaviour

(have tested with main branch & sylvian testing branch and results have been similar to this)

The results below are from using sylvian testing branch build as described here http://bb.osmocom.org/trac/wiki/SIMReader config tx is enabled etc

I can download the layer1 firmware to the phone ok - mobile app seems to run ok aswell but when I try to make a call or sms this is where there's some odd behaviour .

On my first attempt to make a call I can hear the call trying to be made but an automated message is played saying I have dialed an incorrect number (this normally happens if the number is dialed in an incorrect format)

In previous attempts I have tried all the formats I can think of but have never been able to get a successful call to go through as of yet but if I dial it through the phone (without osmocom) normally everything works fine..

07780000000
+447780000000
447780000000
00447780000000

Usually after the first call the phone then mysteriously deregisters from the network there is no service and when I restart osmocon/mobile etc I still cannot register on the network it just keeps scannning frequenceies and failing to connect with the network.

On my first osmocon log when i managed to connect to the network after the call was released there were alot of DSP Error Status: 32 messages and then no service.

I have gone through the logs but I still can't figure out why
a) the call is failing to go through correctly
b) why it seems like I get kicked of the network if I try to make a call

Here are my full outputs

1ST ATTEMPT - MANAGED TO PLACE CALL THEN CONNECTION DROPPED
Osmocon output - https://www.box.com/s/xdqi7azezprf4g7erz9h
Mobile output - https://www.box.com/s/gqcdas9eqso0nchat011
Telnet output - https://www.box.com/s/lcazgabtmous0xheklmc

2ND ATTEMPT - FAILED TO CONNECT
Osmocon output - https://www.box.com/s/c42vi7ows8p14h0hr45m
Mobile output - https://www.box.com/s/eqygysqommur46ywgqrs
Telnet output - https://www.box.com/s/kmympl0g0l8zb3xjyu8d

3RD ATTEMPT - FAILED TO CONNECT
Osmocon output - https://www.box.com/s/gb9aw9p05pqy1v5fpxke
Mobile output - https://www.box.com/s/llo751tuvvu1p5v31eur
Telnet output - https://www.box.com/s/t8e63lqrad87f35uylge

Extract from telnet

OsmocomBB#
% (MS 1)
% Trying to registering with network...

% (MS 1)
% On Network, normal service: Guernsey, T-Mobile
show ms
MS '1' is up, service is normal
  IMEI: 35972800609####
     IMEISV: 359728006093####
     IMEI generation: fixed
  automatic network selection state: A2 on PLMN
                                     MCC=234 MNC=30 (Guernsey, T-Mobile)
  cell selection state: C3 camped normally
                        ARFCN=628(DCS) MCC=234 MNC=30 LAC=0x084f CELLID=0xf65d
                        (Guernsey, T-Mobile)
  radio ressource layer state: idle
  mobility management layer state: MM idle, normal service

OsmocomBB# call 1 +44772228####
OsmocomBB#
% (MS 1)
% Call has been released

% (MS 1)
% On Network, normal service: Guernsey, T-Mobile
call 1 +44772228####
% (MS 1)
% Searching network...
show ms            
% (MS 1)
% On Network, normal service: Guernsey, T-Mobile
call 1 44772228####
OsmocomBB#
% (MS 1)
% Call is proceeding

% (MS 1)
% Call is alerting

% (MS 1)
% Call: Remote hangs up

% (MS 1)
% Trying to registering with network...

% (MS 1)
% Trying to registering with network...

% (MS 1)
% Searching network...

% (MS 1)
% No service.

% (MS 1)
% Power off!

CALL SETUP EXTRACT FROM 1ST MOBILE APP OUTPUT

<000b> gsm48_rr.c:2163 PAGING REQUEST 1
<000b> gsm48_rr.c:2121  TMSI c35448a0 (not for us)
<0009> mnccms.c:570 Make call to 44772228####
<0009> mnccms.c:150  support TCH/H also
<0009> mnccms.c:174  support full rate v2
<0009> mnccms.c:178  support full rate v1
<0009> mnccms.c:187  support half rate v1
<0006> transaction.c:76 ms 1 allocates transaction (proto 3 trans_id 255 callref 2 mem 0x8e7faa0)
<0006> gsm48_cc.c:243 new state NULL -> MM_CONNECTION_PEND
<0006> gsm48_cc.c:507 Sending MMCC_EST_REQ
<0005> gsm48_mm.c:3783 (ms 1) Received 'MMCC_EST_REQ' event in state MM idle
<0005> gsm48_mm.c:3786 -> substate normal service
<0005> gsm48_mm.c:3788 -> callref 2, transaction_id 255
<0005> gsm48_mm.c:3034 Init MM Connection.
<0005> gsm48_mm.c:1436 New MM Connection (proto 0x03 trans_id 255 sapi 0 ref 2)
<0005> gsm48_mm.c:1395 (ref 2) new state IDLE -> CONN_PEND
<0005> gsm48_mm.c:2804 CM SERVICE REQUEST (cause 9)
<0005> gsm48_mm.c:2837 -> Using TMSI
<0001> gsm48_rr.c:5449 (ms 1) Message 'RR_EST_REQ' received in state idle (sapi 0)
<000e> gsm48_rr.c:1307 Establish radio link due to mobility management request
<0003> gsm322.c:4049 (ms 1) Event 'EVENT_LEAVE_IDLE' for Cell selection in state 'C3 camped normally'
<0003> gsm322.c:829 new state 'C3 camped normally' -> 'connected mode 1'
<0003> gsm322.c:3665 Going to camping (normal) ARFCN 628(DCS).
<0003> gsm322.c:468 Sync to ARFCN=628(DCS) rxlev=-84 (Sysinfo, ccch mode NON-COMB)
<0001> gsm48_rr.c:355 new state idle -> connection pending
<0001> gsm48_rr.c:1447 CHANNEL REQUEST: e0 (Orig TCH/F)
<0005> gsm48_mm.c:914 new state MM IDLE, normal service -> wait for RR connection (MM connection)
<0003> gsm322.c:2947 Channel synched. (ARFCN=628(DCS), snr=16, BSIC=49)
<0001> gsm322.c:2968 using DSC of 90
<0003> gsm48_rr.c:4820 Channel provides data.
<0001> gsm48_rr.c:1590 RANDOM ACCESS (requests left 5)
<0001> gsm48_rr.c:1647 RANDOM ACCESS (Tx-integer 12 combined no S(lots) 0 ra 0xe8)
<0001> gsm48_rr.c:1679 Use MS-TXPWR-MAX-CCH power value 0 (30 dBm) with offset 4 dBm
<0001> gsm48_rr.c:1590 RANDOM ACCESS (requests left 4)
<0001> gsm48_rr.c:1647 RANDOM ACCESS (Tx-integer 12 combined no S(lots) 217 ra 0xe6)
<0001> gsm48_rr.c:1679 Use MS-TXPWR-MAX-CCH power value 0 (30 dBm) with offset 4 dBm
<0001> gsm48_rr.c:662 MON: f=628 lev=-82 snr= 0 ber= 29 LAI=234 30 084f ID=f65d
<0001> gsm48_rr.c:2439 IMMEDIATE ASSIGNMENT:
<0001> gsm48_rr.c:2462  (ta 0/0m ra 0xe8 chan_nr 0x41 ARFCN 628(DCS) TS 1 SS 0 TSC 1)
<0001> gsm48_rr.c:2375 request e8 matches (fn=11,12,35)
<0001> gsm48_rr.c:2487 resetting scheduler
<0001> gsm48_rr.c:3225 sending establish message
<0001> gsm48_rr.c:227 Using and incrementing V(SD) = 0 (pdisc 5)
<0001> gsm48_rr.c:2964 setting indicated TA 0 (actual TA 0)
<0001> gsm48_rr.c:2979 using last BCCH timeout 24
<0001> gsm48_rr.c:834 stopping pending timer T_meas
<0001> gsm48_rr.c:2864 MEAS REP: pwr=0 TA=0 meas-invalid=1 rxlev-full=-110 rxlev-sub=-110 rxqual-full=0 rxqual-sub=0 dtx 0 ba 0 no-ncell-n 7
<0001> gsm48_rr.c:2997 establishing channel in dedicated mode
<0001> gsm48_rr.c:3001  Channel type 64, subch 0, ts 1, mode 0, audio-mode 5, cipher 1
<0001> gsm48_rr.c:2439 IMMEDIATE ASSIGNMENT:
<0001> gsm48_rr.c:2462  (ta 0/0m ra 0xe8 chan_nr 0x41 ARFCN 628(DCS) TS 1 SS 0 TSC 1)
<0001> gsm48_rr.c:2472 Ignoring, channel already assigned.
<0001> gsm48_rr.c:2439 IMMEDIATE ASSIGNMENT:
<0001> gsm48_rr.c:2462  (ta 0/0m ra 0xe8 chan_nr 0x41 ARFCN 628(DCS) TS 1 SS 0 TSC 1)
<0001> gsm48_rr.c:2472 Ignoring, channel already assigned.
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:1980 New SYSTEM INFORMATION 5
<0001> gsm48_rr.c:1723 Complete set of SI5* for BA(1)
<0001> gsm48_rr.c:1741 SI5* report arfcn 571(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 581(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 589(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 593(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 624(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 626(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 630(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 632(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 634(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 640(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 642(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 644(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 646(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 652(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 654(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 656(DCS)
<0001> gsm48_rr.c:355 new state connection pending -> dedicated
<0005> gsm48_mm.c:3911 (ms 1) Received 'RR_EST_CNF' from RR in state wait for RR connection (MM connection) (sapi 0)
<0005> gsm48_mm.c:453 starting T3230 (MM connection timeout) with 15.0 seconds
<0005> gsm48_mm.c:924 new state wait for RR connection (MM connection) -> wait for outgoing MM connection
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:987 CIPHERING MODE COMMAND (sc=1, algo=A5/1 cr=0)
<0001> gsm48_rr.c:928 CIPHERING MODE COMPLETE (cr 0)
<0005> gsm48_mm.c:3911 (ms 1) Received 'RR_SYNC_IND' from RR in state wait for outgoing MM connection (sapi 0)
<0005> gsm48_mm.c:517 stopping pending (MM connection timeout) timer T3230
<0005> gsm48_mm.c:924 new state wait for outgoing MM connection -> MM connection active
<0005> gsm48_mm.c:1395 (ref 2) new state CONN_PEND -> DEDICATED
<0006> gsm48_cc.c:2161 (ms 1) Received 'MMCC_EST_CNF' in CC state MM_CONNECTION_PEND
<0006> gsm48_cc.c:541 sending SETUP
<0006> gsm48_cc.c:345 starting timer T303 with 30 seconds
<0006> gsm48_cc.c:243 new state MM_CONNECTION_PEND -> INITIATED
<0006> gsm48_cc.c:182 Sending 'SETUP' using MMCC_DATA_REQ (callref=2, transaction_id=0)
<0005> gsm48_mm.c:3783 (ms 1) Received 'MMCC_DATA_REQ' event in state MM connection active
<0005> gsm48_mm.c:3788 -> callref 2, transaction_id 0
<0001> gsm48_rr.c:5449 (ms 1) Message 'RR_DATA_REQ' received in state dedicated (sapi 0)
<0001> gsm48_rr.c:227 Using and incrementing V(SD) = 1 (pdisc 5)
<0001> gsm48_rr.c:662 MON: f=628 lev=-82 snr= 0 ber= 10 LAI=234 30 084f ID=f65d TA=0 pwr=0 TS=1/0
<0001> gsm48_rr.c:2864 MEAS REP: pwr=0 TA=0 meas-invalid=0 rxlev-full=-82 rxlev-sub=-82 rxqual-full=0 rxqual-sub=0 dtx 0 ba 1 no-ncell-n 0
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:2011 New SYSTEM INFORMATION 5bis
<0001> gsm48_rr.c:1723 Complete set of SI5* for BA(1)
<0001> gsm48_rr.c:1741 SI5* report arfcn 571(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 581(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 589(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 593(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 624(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 626(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 630(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 632(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 634(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 640(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 642(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 644(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 646(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 652(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 654(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 656(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 658(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 660(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 662(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 664(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 666(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 760(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 765(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 793(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 797(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 837(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 846(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 860(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 862(DCS)
<0005> gsm48_mm.c:3911 (ms 1) Received 'RR_DATA_IND' from RR in state MM connection active (sapi 0)
<0005> gsm48_mm.c:4100 (ms 1) Received 'MT_MM_ID_REQ' in MM state MM connection active
<0005> gsm48_mm.c:490 stopping pending (periodic loc. upd. delay) timer T3212
<0005> gsm48_mm.c:1750 IDENTITY REQUEST (mi_type 3)
<0005> gsm48_mm.c:1776 IDENTITY RESPONSE
<0001> gsm48_rr.c:5449 (ms 1) Message 'RR_DATA_REQ' received in state dedicated (sapi 0)
<0001> gsm48_rr.c:227 Using and incrementing V(SD) = 0 (pdisc 5)
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:2042 New SYSTEM INFORMATION 5ter
<0001> gsm48_rr.c:1723 Complete set of SI5* for BA(1)
<0001> gsm48_rr.c:1741 SI5* report arfcn 571(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 581(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 589(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 593(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 624(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 626(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 630(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 632(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 634(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 640(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 642(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 644(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 646(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 652(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 654(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 656(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 658(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 660(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 662(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 664(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 666(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 760(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 765(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 793(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 797(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 837(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 846(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 860(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 862(DCS)
<0005> gsm48_mm.c:3911 (ms 1) Received 'RR_DATA_IND' from RR in state MM connection active (sapi 0)
<0006> gsm48_cc.c:2161 (ms 1) Received 'MMCC_DATA_IND' in CC state INITIATED
<0006> gsm48_cc.c:2115 (ms 1) Received 'CALL_PROC' in CC state INITIATED
<0006> gsm48_cc.c:661 sending CALL PROCEEDING
<0006> gsm48_cc.c:357 stopping pending timer T303
<0006> gsm48_cc.c:243 new state INITIATED -> MO_CALL_PROC
<0006> gsm48_cc.c:196 (ms 1 ti 0) Sending 'MNCC_CALL_PROC_IND' to MNCC.
<0009> mnccms.c:378 Call is proceeding
<0001> gsm48_rr.c:662 MON: f=628 lev=-82 snr= 0 ber= 19 LAI=234 30 084f ID=f65d TA=0 pwr=0 TS=1/0
<0001> gsm48_rr.c:2750 BA-IND missmatch on SI5*<0001> gsm48_rr.c:2864 MEAS REP: pwr=0 TA=0 meas-invalid=0 rxlev-full=-82 rxlev-sub=-82 rxqual-full=0 rxqual-sub=0 dtx 0 ba 1 no-ncell-n 7
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:2075 New SYSTEM INFORMATION 6 (mcc 234 mnc 30 lac 0x084f SACCH-timeout 24)
<0001> gsm48_rr.c:2078 using (new) SACCH timeout 24
<0001> gsm48_rr.c:3685 ASSIGNMENT COMMAND
<0001> gsm48_rr.c:3735  after: (chan_nr 0x08 MAIO 1 HSN 62 TS 0 SS 0 TSC 1)
<0001> gsm48_rr.c:3779  after: hopping required and mobile allocation available
<0001> gsm48_rr.c:3868  both: using cell channel description in case of mobile allocation
<0001> gsm48_rr.c:3889  both: changing channel mode 0x21
<0001> gsm48_rr.c:3909  both: (tx_power 0 TA 0)
<0001> gsm48_rr.c:283 Mode: full-rate speech V2
<0001> gsm48_rr.c:3063 decoding mobile allocation
<0001> gsm48_rr.c:3066 using cell channel descr.
<0001> sysinfo.c:412 Serving cell ARFCN #0: 601
<0001> sysinfo.c:412 Serving cell ARFCN #1: 617
<0001> sysinfo.c:412 Serving cell ARFCN #2: 649
<0001> sysinfo.c:412 Serving cell ARFCN #3: 675
<0001> sysinfo.c:412 Serving cell ARFCN #4: 691
<0001> sysinfo.c:426 Hopping ARFCN: 0 (bit 601)
<0001> sysinfo.c:426 Hopping ARFCN: 1 (bit 617)
<0001> sysinfo.c:426 Hopping ARFCN: 2 (bit 649)
<0001> sysinfo.c:426 Hopping ARFCN: 3 (bit 675)
<0001> sysinfo.c:426 Hopping ARFCN: 4 (bit 691)
<0001> gsm48_rr.c:3967 request suspension of data link
<0001> gsm48_rr.c:4423 suspension coplete, leaving dedicated mode
<0001> gsm48_rr.c:3063 decoding mobile allocation
<0001> gsm48_rr.c:3066 using cell channel descr.
<0001> sysinfo.c:412 Serving cell ARFCN #0: 601
<0001> sysinfo.c:412 Serving cell ARFCN #1: 617
<0001> sysinfo.c:412 Serving cell ARFCN #2: 649
<0001> sysinfo.c:412 Serving cell ARFCN #3: 675
<0001> sysinfo.c:412 Serving cell ARFCN #4: 691
<0001> sysinfo.c:426 Hopping ARFCN: 0 (bit 601)
<0001> sysinfo.c:426 Hopping ARFCN: 1 (bit 617)
<0001> sysinfo.c:426 Hopping ARFCN: 2 (bit 649)
<0001> sysinfo.c:426 Hopping ARFCN: 3 (bit 675)
<0001> sysinfo.c:426 Hopping ARFCN: 4 (bit 691)
<0001> gsm48_rr.c:2964 setting indicated TA 0 (actual TA 0)
<0001> gsm48_rr.c:2975 using last SACCH timeout 24
<0001> gsm48_rr.c:834 stopping pending timer T_meas
<0001> gsm48_rr.c:2750 BA-IND missmatch on SI5*<0001> gsm48_rr.c:2864 MEAS REP: pwr=0 TA=0 meas-invalid=1 rxlev-full=-110 rxlev-sub=-110 rxqual-full=0 rxqual-sub=0 dtx 0 ba 1 no-ncell-n 7
<0001> gsm48_rr.c:2997 establishing channel in dedicated mode
<0001> gsm48_rr.c:3001  Channel type 8, subch 0, ts 0, mode 33, audio-mode 5, cipher 1
<0001> gsm48_rr.c:4458 request resume of data link
<0001> gsm48_rr.c:3617 ASSIGNMENT COMPLETE (cause #0)
Dropping frame with 88 bit errors
Dropping frame with 79 bit errors
Dropping frame with 83 bit errors
Dropping frame with 79 bit errors
Dropping frame with 84 bit errors
Dropping frame with 88 bit errors
Dropping frame with 90 bit errors
Dropping frame with 79 bit errors
<0001> gsm48_rr.c:4402 data link is resumed
<0005> gsm48_mm.c:3911 (ms 1) Received 'RR_DATA_IND' from RR in state MM connection active (sapi 0)
<0006> gsm48_cc.c:2161 (ms 1) Received 'MMCC_DATA_IND' in CC state MO_CALL_PROC
<0006> gsm48_cc.c:2115 (ms 1) Received 'ALERTING' in CC state MO_CALL_PROC
<0006> gsm48_cc.c:717 received ALERTING
<0006> gsm48_cc.c:243 new state MO_CALL_PROC -> CALL_DELIVERED
<0006> gsm48_cc.c:196 (ms 1 ti 0) Sending 'MNCC_ALERT_IND' to MNCC.
<0009> mnccms.c:387 Call is alerting
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:1980 New SYSTEM INFORMATION 5
<0001> gsm48_rr.c:1723 Complete set of SI5* for BA(1)
<0001> gsm48_rr.c:1741 SI5* report arfcn 571(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 581(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 589(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 593(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 624(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 626(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 630(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 632(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 634(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 640(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 642(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 644(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 646(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 652(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 654(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 656(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 658(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 660(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 662(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 664(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 666(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 760(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 765(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 793(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 797(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 837(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 846(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 860(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 862(DCS)
<0001> gsm48_rr.c:662 MON: f=628 lev=-93 snr=33 ber=109 LAI=234 30 084f ID=f65d TA=0 pwr=0 TS=0
<0001> gsm48_rr.c:2864 MEAS REP: pwr=0 TA=0 meas-invalid=0 rxlev-full=-93 rxlev-sub=-93 rxqual-full=0 rxqual-sub=0 dtx 0 ba 1 no-ncell-n 0
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:2011 New SYSTEM INFORMATION 5bis
<0001> gsm48_rr.c:1723 Complete set of SI5* for BA(1)
<0001> gsm48_rr.c:1741 SI5* report arfcn 571(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 581(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 589(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 593(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 624(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 626(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 630(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 632(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 634(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 640(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 642(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 644(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 646(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 652(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 654(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 656(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 658(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 660(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 662(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 664(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 666(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 760(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 765(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 793(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 797(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 837(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 846(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 860(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 862(DCS)
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:2042 New SYSTEM INFORMATION 5ter
<0001> gsm48_rr.c:1723 Complete set of SI5* for BA(1)
<0001> gsm48_rr.c:1741 SI5* report arfcn 571(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 581(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 589(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 593(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 624(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 626(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 630(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 632(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 634(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 640(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 642(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 644(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 646(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 652(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 654(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 656(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 658(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 660(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 662(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 664(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 666(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 760(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 765(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 793(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 797(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 837(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 846(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 860(DCS)
<0001> gsm48_rr.c:1741 SI5* report arfcn 862(DCS)
<0001> gsm48_rr.c:662 MON: f=628 lev=-87 snr= 0 ber=  0 LAI=234 30 084f ID=f65d TA=0 pwr=0 TS=0
<0001> gsm48_rr.c:2750 BA-IND missmatch on SI5*<0001> gsm48_rr.c:2864 MEAS REP: pwr=0 TA=0 meas-invalid=0 rxlev-full=-87 rxlev-sub=-87 rxqual-full=0 rxqual-sub=0 dtx 0 ba 1 no-ncell-n 7
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:662 MON: f=628 lev=-87 snr= 0 ber= 17 LAI=234 30 084f ID=f65d TA=0 pwr=0 TS=0
<0001> gsm48_rr.c:2750 BA-IND missmatch on SI5*<0001> gsm48_rr.c:2864 MEAS REP: pwr=0 TA=0 meas-invalid=0 rxlev-full=-87 rxlev-sub=-87 rxqual-full=0 rxqual-sub=0 dtx 0 ba 1 no-ncell-n 7
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:662 MON: f=628 lev=-86 snr= 0 ber= 36 LAI=234 30 084f ID=f65d TA=0 pwr=0 TS=0
<0001> gsm48_rr.c:2750 BA-IND missmatch on SI5*<0001> gsm48_rr.c:2864 MEAS REP: pwr=0 TA=0 meas-invalid=0 rxlev-full=-86 rxlev-sub=-86 rxqual-full=0 rxqual-sub=0 dtx 0 ba 1 no-ncell-n 7
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:662 MON: f=628 lev=-87 snr= 0 ber=  0 LAI=234 30 084f ID=f65d TA=0 pwr=0 TS=0
<0001> gsm48_rr.c:2750 BA-IND missmatch on SI5*<0001> gsm48_rr.c:2864 MEAS REP: pwr=0 TA=0 meas-invalid=0 rxlev-full=-87 rxlev-sub=-87 rxqual-full=0 rxqual-sub=0 dtx 0 ba 1 no-ncell-n 7
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:662 MON: f=628 lev=-87 snr= 0 ber=101 LAI=234 30 084f ID=f65d TA=0 pwr=0 TS=0
<0001> gsm48_rr.c:2750 BA-IND missmatch on SI5*<0001> gsm48_rr.c:2864 MEAS REP: pwr=0 TA=0 meas-invalid=0 rxlev-full=-87 rxlev-sub=-87 rxqual-full=0 rxqual-sub=0 dtx 0 ba 1 no-ncell-n 7
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:662 MON: f=628 lev=-85 snr= 0 ber=116 LAI=234 30 084f ID=f65d TA=0 pwr=0 TS=0
<0001> gsm48_rr.c:2750 BA-IND missmatch on SI5*<0001> gsm48_rr.c:2864 MEAS REP: pwr=0 TA=0 meas-invalid=0 rxlev-full=-85 rxlev-sub=-85 rxqual-full=0 rxqual-sub=0 dtx 0 ba 1 no-ncell-n 7
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0001> gsm48_rr.c:4767 Indicated ta 0 (actual ta 0)
<0001> gsm48_rr.c:4769 Indicated tx_power 0
<0005> gsm48_mm.c:3911 (ms 1) Received 'RR_DATA_IND' from RR in state MM connection active (sapi 0)
<0006> gsm48_cc.c:2161 (ms 1) Received 'MMCC_DATA_IND' in CC state CALL_DELIVERED
<0006> gsm48_cc.c:2115 (ms 1) Received 'DISCONNECT' in CC state CALL_DELIVERED
<0006> gsm48_cc.c:1680 received DISCONNECT
<0006> gsm48_cc.c:243 new state CALL_DELIVERED -> DISCONNECT_IND
<0006> gsm48_cc.c:196 (ms 1 ti 0) Sending 'MNCC_DISC_IND' to MNCC.
<0009> mnccms.c:355 Call has been disconnected (cause 16)
<0009> mnccms.c:71 (call 2) Call removed.
<0006> gsm48_cc.c:1590 sending RELEASE
<0006> gsm48_cc.c:345 starting timer T308 with 30 seconds
<0006> gsm48_cc.c:243 new state DISCONNECT_IND -> RELEASE_REQ
<0006> gsm48_cc.c:182 Sending 'RELEASE' using MMCC_DATA_REQ (callref=2, transaction_id=0)
<0005> gsm48_mm.c:3783 (ms 1) Received 'MMCC_DATA_REQ' event in state MM connection active
<0005> gsm48_mm.c:3788 -> callref 2, transaction_id 0
<0001> gsm48_rr.c:5449 (ms 1) Message 'RR_DATA_REQ' received in state dedicated (sapi 0)
<0001> gsm48_rr.c:227 Using and incrementing V(SD) = 1 (pdisc 5)
<0001> gsm48_rr.c:662 MON: f=628 lev=-87 snr= 0 ber= 47 LAI=234 30 084f ID=f65d TA=0 pwr=0 TS=0
<0001> gsm48_rr.c:2750 BA-IND missmatch on SI5*<0001> gsm48_rr.c:2864 MEAS REP: pwr=0 TA=0 meas-invalid=0 rxlev-full=-87 rxlev-sub=-87 rxqual-full=0 rxqual-sub=0 dtx 0 ba 1 no-ncell-n 7
<0005> gsm48_mm.c:3911 (ms 1) Received 'RR_DATA_IND' from RR in state MM connection active (sapi 0)
<0006> gsm48_cc.c:2161 (ms 1) Received 'MMCC_DATA_IND' in CC state RELEASE_REQ
<0006> gsm48_cc.c:2115 (ms 1) Received 'RELEASE_COMPL' in CC state RELEASE_REQ
<0006> gsm48_cc.c:1798 received RELEASE COMPLETE
<0006> gsm48_cc.c:357 stopping pending timer T308
<0006> gsm48_cc.c:196 (ms 1 ti 0) Sending 'MNCC_REL_CNF' to MNCC.
<0006> gsm48_cc.c:399 Sending MMCC_REL_REQ
<0005> gsm48_mm.c:3783 (ms 1) Received 'MMCC_REL_REQ' event in state MM connection active
<0005> gsm48_mm.c:3788 -> callref 2, transaction_id 0
<0005> gsm48_mm.c:1453 Freeing MM Connection
<0005> gsm48_mm.c:1395 (ref 2) new state DEDICATED -> IDLE
<0005> gsm48_mm.c:462 starting T3240 (RR release timeout) with 10.0 seconds
<0005> gsm48_mm.c:924 new state MM connection active -> wait for network command
<0006> gsm48_cc.c:243 new state RELEASE_REQ -> NULL
<0006> transaction.c:104 ms 1 frees transaction (mem 0x8e7faa0)
<0009> mnccms.c:275 Rejecting incoming call (callref 2)
<0001> gsm48_rr.c:3389 channel release request with cause 0x00
<0001> gsm48_rr.c:355 new state dedicated -> release pending
<0001> gsm48_rr.c:798 starting T3110 with 1.500 seconds
LOSS counter for ACCH 23
Dropping frame with 82 bit errors
Reply | Threaded
Open this post in threaded view
|

Re: OsmocomBB Mobile Call Setup Weird behaviour

Sylvain Munaut
Hi,

> The results below are from using sylvian testing branch build as described
> here  http://bb.osmocom.org/trac/wiki/SIMReader
> <http://bb.osmocom.org/trac/wiki/SIMReader>

Retry with the main branch (and make sure the phone has been hard
rebooted / battery removed).

The sylvain/testing branch currently includes some _highly_
experimental DSP patch that seems to break some stuff.

Cheers,

    Sylvain

Reply | Threaded
Open this post in threaded view
|

Re: OsmocomBB Mobile Call Setup Weird behaviour

dagar
Thanks just did a hard reset and ran on main branch and its working ok :) on one sim at least planning to test more later....