CalypsoBTS and modern OsmoBSC

Anton Gorbachev antgorka at gmail.com
Thu May 11 18:01:20 UTC 2017


Hi,

I could setup calypsoBTS, send sms and even do voice calls but only for few
seconds. Then capypsoBTS crashes.

@Vadim,
I remember you wrote somewhere you could setup calls for several minutes?
Maybe there are some amr settings or I need to use another codec or
something, don't you remember which setting did you use for voice call
routine?


What I can see in logs after I stop hearing anything:

OsmoBTS:

<0006> scheduler_trx.c:702 TCH/H(0) has not been served !! No prim for
trx=0 ts=1 at fn=1119261 to transmit.
<0006> scheduler_trx.c:535 TCH/H(1) Transmitting 'bad AMR frame' trx=0 ts=1
at fn=1119262.
<0006> scheduler_trx.c:702 TCH/H(1) has not been served !! No prim for
trx=0 ts=1 at fn=1119262 to transmit.
<0006> scheduler.c:524 TCH RTS.ind: chan=TCH/H(0) chan_nr=0x11 fn=1119269
ts=1 trx=0
<0006> scheduler.c:423 PH-DATA.req: chan_nr=0x11 link_id=0x00 fn=1119269
ts=1 trx=0
<0006> scheduler.c:446 TCH.req: chan_nr=0x11 fn=1119269 ts=1 trx=0
<0006> scheduler.c:524 TCH RTS.ind: chan=TCH/H(1) chan_nr=0x19 fn=1119270
ts=1 trx=0
<0006> scheduler.c:423 PH-DATA.req: chan_nr=0x19 link_id=0x00 fn=1119270
ts=1 trx=0
<0006> scheduler.c:446 TCH.req: chan_nr=0x19 fn=1119270 ts=1 trx=0
<0006> scheduler_trx.c:354 Missing TCH bursts detected, sending BFI for
TCH/H(0)
<0006> scheduler_trx.c:535 TCH/H(0) Transmitting 'bad AMR frame' trx=0 ts=1
at fn=1119265.
<0006> scheduler_trx.c:702 TCH/H(0) has not been served !! No prim for
trx=0 ts=1 at fn=1119265 to transmit.
<0006> scheduler_trx.c:354 Missing TCH bursts detected, sending BFI for
TCH/H(1)
<0006> scheduler_trx.c:535 TCH/H(1) Transmitting 'bad AMR frame' trx=0 ts=1
at fn=1119266.
<0006> scheduler_trx.c:702 TCH/H(1) has not been served !! No prim for
trx=0 ts=1 at fn=1119266 to transmit.
<0006> scheduler.c:524 TCH RTS.ind: chan=TCH/H(0) chan_nr=0x11 fn=1119274
ts=1 trx=0
<0006> scheduler.c:446 TCH.req: chan_nr=0x11 fn=1119274 ts=1 trx=0
<0006> scheduler_trx.c:535 TCH/H(0) Transmitting 'bad AMR frame' trx=0 ts=1
at fn=1119269.
<0006> scheduler_trx.c:702 TCH/H(0) has not been served !! No prim for
trx=0 ts=1 at fn=1119269 to transmit.

OsmoBSC:
<0001> gsm_04_08.c:3894 (bts 0 trx 0 ts 1 ti 8 sub 44680) Received 'SETUP'
from MS in state 0 (NULL)
<0001> gsm_04_08.c:3899 Unknown transaction ID 8, creating new trans.
<0001> transaction.c:71 subscr=0xd67f60, net=0xc08d50
<0001> gsm_04_08.c:1623 new state NULL -> INITIATED
<0001> gsm_04_08.c:2302 Subscriber 250996689298609 (44680) sends SETUP to
43926
<0001> gsm_04_08.c:1685 (bts 0 trx 0 ts 1 ti 8 sub 44680) Sending
'MNCC_SETUP_IND' to MNCC.
<0001> gsm_04_08.c:3796 (bts 0 trx 0 ts 1 ti 08 sub 44680) Received
'MNCC_CALL_PROC_REQ' from MNCC in state 1 (INITIATED)
<0001> gsm_04_08.c:1623 new state INITIATED -> MO_CALL_PROC
<0001> gsm_04_08.c:143 (bts 0 trx 0 ts 1 ti 80) Sending 'CALL_PROC' to MS.
<0001> gsm_04_08.c:3796 (bts 0 trx 0 ts 1 ti 08 sub 44680) Received
'MNCC_LCHAN_MODIFY' from MNCC in state 3 (MO_CALL_PROC)
<000a> bsc_api.c:404 Sending (bts=0,trx=0,ts=1,ss=0) ChanModify for speech:
SPEECH_AMR on channel TCH_H
<0003> gsm_04_08_utils.c:512 -> CHANNEL MODE MODIFY mode=0x41
<0001> transaction.c:71 subscr=0xd77ad0, net=0xc08d50
<0002> gsm_subscriber.c:190 Subscriber 250202101944311 not paged yet.
<0000> abis_rsl.c:2051 (bts=0,trx=0,ts=1,ss=0) SAPI=0 DATA INDICATION
<0003> gsm_04_08_utils.c:537 CHANNEL MODE MODIFY ACK
<0004> abis_rsl.c:2268 (bts=0,trx=0,ts=1,ss=0) IPAC_BIND speech_mode=0x15
RTP_PAYLOAD=98
<0003> osmo_msc.c:76 MSC assign complete (do nothing).
<0004> abis_rsl.c:1608 (bts=0,trx=0,ts=1,ss=0) CHANNEL MODE MODIFY ACK
<0004> abis_rsl.c:2449 (bts=0,trx=0,ts=1,ss=0) IPAC_CRCX_ACK
LOCAL_IP=127.0.0.1 LOCAL_PORT=10880 CON_ID=0
<0000> chan_alloc.c:352 (bts=0,trx=0,ts=1,pchan=TCH/H) Allocating lchan=1
as TCH_H
<0004> abis_rsl.c:1863 (bts=0,trx=0,ts=1,ss=1) Activating ARFCN(866) SS(1)
lctype TCH_H r=PAGING ra=0x2d ta=0
<0004> abis_rsl.c:585 (bts=0,trx=0,ts=1,pchan=TCH/H) Tx RSL Channel
Activate with act_type=INITIAL
<0004> abis_rsl.c:1221 (bts=0,trx=0,ts=1,ss=1) state NONE -> ACTIVATION
REQUESTED
<0004> abis_rsl.c:1587 (bts=0,trx=0,ts=1,ss=1) CHANNEL ACTIVATE ACK
<0004> abis_rsl.c:1221 (bts=0,trx=0,ts=1,ss=1) state ACTIVATION REQUESTED
-> ACTIVE
<0000> abis_rsl.c:2051 (bts=0,trx=0,ts=1,ss=1) SAPI=0 ESTABLISH INDICATION
<0000> gsm_04_08.c:3999 Dispatching 04.08 message, pdisc=6
<0003> gsm_04_08.c:1462 PAGING RESPONSE: MI(TMSI)=2399361011
<0003> gsm_04_08.c:1495 <- Channel was requested by 250202101944311
<0001> gsm_04_08.c:1755 Paging subscr 43926 succeeded!
<0001> gsm_04_08.c:2226 starting timer T303 with 30 seconds
<0001> gsm_04_08.c:1623 new state NULL -> CALL_PRESENT
<0001> gsm_04_08.c:143 (bts 0 trx 0 ts 1 ti 00) Sending 'SETUP' to MS.
<0000> abis_rsl.c:2051 (bts=0,trx=0,ts=1,ss=1) SAPI=0 DATA INDICATION
<0000> gsm_04_08.c:3999 Dispatching 04.08 message, pdisc=3
<0001> gsm_04_08.c:3894 (bts 0 trx 0 ts 1 ti 0 sub 43926) Received
'CALL_CONF' from MS in state 6 (CALL_PRESENT)
<0001> gsm_04_08.c:1665 stopping pending timer T303
<0001> gsm_04_08.c:2226 starting timer T310 with 180 seconds
<0001> gsm_04_08.c:1623 new state CALL_PRESENT -> MO_TERM_CALL_CONF
<0001> gsm_04_08.c:1685 (bts 0 trx 0 ts 1 ti 0 sub 43926) Sending
'MNCC_CALL_CONF_IND' to MNCC.
<0001> gsm_04_08.c:3796 (bts 0 trx 0 ts 1 ti 00 sub 43926) Received
'MNCC_LCHAN_MODIFY' from MNCC in state 9 (MO_TERM_CALL_CONF)
<000a> bsc_api.c:404 Sending (bts=0,trx=0,ts=1,ss=1) ChanModify for speech:
SPEECH_AMR on channel TCH_H
<0003> gsm_04_08_utils.c:512 -> CHANNEL MODE MODIFY mode=0x41
<0000> abis_rsl.c:2051 (bts=0,trx=0,ts=1,ss=1) SAPI=0 DATA INDICATION
<0003> gsm_04_08_utils.c:537 CHANNEL MODE MODIFY ACK
<0004> abis_rsl.c:2268 (bts=0,trx=0,ts=1,ss=1) IPAC_BIND speech_mode=0x15
RTP_PAYLOAD=98
<0003> osmo_msc.c:76 MSC assign complete (do nothing).
<0004> abis_rsl.c:1608 (bts=0,trx=0,ts=1,ss=1) CHANNEL MODE MODIFY ACK
<0004> abis_rsl.c:2449 (bts=0,trx=0,ts=1,ss=1) IPAC_CRCX_ACK
LOCAL_IP=127.0.0.1 LOCAL_PORT=52342 CON_ID=0
<0000> abis_rsl.c:2051 (bts=0,trx=0,ts=1,ss=1) SAPI=0 DATA INDICATION
<0000> gsm_04_08.c:3999 Dispatching 04.08 message, pdisc=3
<0001> gsm_04_08.c:3894 (bts 0 trx 0 ts 1 ti 0 sub 43926) Received
'ALERTING' from MS in state 9 (MO_TERM_CALL_CONF)
<0001> gsm_04_08.c:1665 stopping pending timer T310
<0001> gsm_04_08.c:2226 starting timer T301 with 180 seconds
<0001> gsm_04_08.c:1623 new state MO_TERM_CALL_CONF -> CALL_RECEIVED
<0001> gsm_04_08.c:1685 (bts 0 trx 0 ts 1 ti 0 sub 43926) Sending
'MNCC_ALERT_IND' to MNCC.
<0001> gsm_04_08.c:3796 (bts 0 trx 0 ts 1 ti 08 sub 44680) Received
'MNCC_ALERT_REQ' from MNCC in state 3 (MO_CALL_PROC)
<0001> gsm_04_08.c:1623 new state MO_CALL_PROC -> CALL_DELIVERED
<0001> gsm_04_08.c:143 (bts 0 trx 0 ts 1 ti 80) Sending 'ALERTING' to MS.
<0000> abis_rsl.c:2051 (bts=0,trx=0,ts=1,ss=1) SAPI=0 DATA INDICATION
<0000> gsm_04_08.c:3999 Dispatching 04.08 message, pdisc=3
<0001> gsm_04_08.c:3894 (bts 0 trx 0 ts 1 ti 0 sub 43926) Received
'CONNECT' from MS in state 7 (CALL_RECEIVED)
<0001> gsm_04_08.c:1665 stopping pending timer T301
<0001> gsm_04_08.c:1623 new state CALL_RECEIVED -> CONNECT_REQUEST
<0001> gsm_04_08.c:1685 (bts 0 trx 0 ts 1 ti 0 sub 43926) Sending
'MNCC_SETUP_CNF' to MNCC.
<0001> gsm_04_08.c:3796 (bts 0 trx 0 ts 1 ti 00 sub 43926) Received
'MNCC_SETUP_COMPL_REQ' from MNCC in state 8 (CONNECT_REQUEST)
<0001> gsm_04_08.c:1623 new state CONNECT_REQUEST -> ACTIVE
<0001> gsm_04_08.c:143 (bts 0 trx 0 ts 1 ti 00) Sending 'CONNECT_ACK' to MS.
<0001> gsm_04_08.c:3796 (bts 0 trx 0 ts 1 ti 08 sub 44680) Received
'MNCC_SETUP_RSP' from MNCC in state 4 (CALL_DELIVERED)
<0001> gsm_04_08.c:2226 starting timer T313 with 30 seconds
<0001> gsm_04_08.c:1623 new state CALL_DELIVERED -> CONNECT_IND
<0001> gsm_04_08.c:143 (bts 0 trx 0 ts 1 ti 80) Sending 'CONNECT' to MS.
<0001> gsm_04_08.c:1939 Setting up TCH map between (bts=0,trx=0,ts=1,TCH_H)
and (bts=0,trx=0,ts=1,TCH_H)
<0004> abis_rsl.c:2307 (bts=0,trx=0,ts=1,ss=1) IPAC_MDCX IP=127.0.0.1
PORT=30002 RTP_PAYLOAD=98 RTP_PAYLOAD2=0 CONN_ID=0 speech_mode=0x05
<0004> abis_rsl.c:2307 (bts=0,trx=0,ts=1,ss=0) IPAC_MDCX IP=127.0.0.1
PORT=30000 RTP_PAYLOAD=98 RTP_PAYLOAD2=0 CONN_ID=0 speech_mode=0x05
<0004> abis_rsl.c:2459 (bts=0,trx=0,ts=1,ss=1) IPAC_MDCX_ACK
LOCAL_IP=127.0.0.1 LOCAL_PORT=52342 CON_ID=0
<0004> abis_rsl.c:2459 (bts=0,trx=0,ts=1,ss=0) IPAC_MDCX_ACK
LOCAL_IP=127.0.0.1 LOCAL_PORT=10880 CON_ID=0
<0000> abis_rsl.c:2051 (bts=0,trx=0,ts=1,ss=0) SAPI=0 DATA INDICATION
<0000> gsm_04_08.c:3999 Dispatching 04.08 message, pdisc=3
<0001> gsm_04_08.c:3894 (bts 0 trx 0 ts 1 ti 8 sub 44680) Received
'CONNECT_ACK' from MS in state 28 (CONNECT_IND)
<0001> gsm_04_08.c:1665 stopping pending timer T313
<0001> gsm_04_08.c:1623 new state CONNECT_IND -> ACTIVE
<0001> gsm_04_08.c:1685 (bts 0 trx 0 ts 1 ti 8 sub 44680) Sending
'MNCC_SETUP_COMPL_IND' to MNCC.
<0000> abis_rsl.c:2051 (bts=0,trx=0,ts=1,ss=0) SAPI=0 DATA INDICATION
<0000> gsm_04_08.c:3999 Dispatching 04.08 message, pdisc=3
<0001> gsm_04_08.c:3894 (bts 0 trx 0 ts 1 ti 8 sub 44680) Received
'DISCONNECT' from MS in state 10 (ACTIVE)
<0001> gsm_04_08.c:1623 new state ACTIVE -> DISCONNECT_IND
<0001> gsm_04_08.c:1685 (bts 0 trx 0 ts 1 ti 8 sub 44680) Sending
'MNCC_DISC_IND' to MNCC.
<0001> gsm_04_08.c:3796 (bts 0 trx 0 ts 1 ti 08 sub 44680) Received
'MNCC_REL_REQ' from MNCC in state 12 (DISCONNECT_IND)
<0001> gsm_04_08.c:2226 starting timer T308 with 10 seconds
<0001> gsm_04_08.c:1623 new state DISCONNECT_IND -> RELEASE_REQ
<0001> gsm_04_08.c:143 (bts 0 trx 0 ts 1 ti 80) Sending 'RELEASE' to MS.
<0001> gsm_04_08.c:3796 (bts 0 trx 0 ts 1 ti 00 sub 43926) Received
'MNCC_DISC_REQ' from MNCC in state 10 (ACTIVE)
<0001> gsm_04_08.c:2226 starting timer T306 with 30 seconds
<0001> gsm_04_08.c:1623 new state ACTIVE -> DISCONNECT_IND
<0001> gsm_04_08.c:143 (bts 0 trx 0 ts 1 ti 00) Sending 'DISCONNECT' to MS.
<0000> abis_rsl.c:2051 (bts=0,trx=0,ts=1,ss=1) SAPI=0 DATA INDICATION
<0000> gsm_04_08.c:3999 Dispatching 04.08 message, pdisc=3
<0001> gsm_04_08.c:3894 (bts 0 trx 0 ts 1 ti 0 sub 43926) Received
'DISCONNECT' from MS in state 12 (DISCONNECT_IND)
<0001> gsm_04_08.c:1665 stopping pending timer T306
<0001> gsm_04_08.c:1623 new state DISCONNECT_IND -> DISCONNECT_IND
<0001> gsm_04_08.c:1685 (bts 0 trx 0 ts 1 ti 0 sub 43926) Sending
'MNCC_DISC_IND' to MNCC.
<0001> gsm_04_08.c:3796 (bts 0 trx 0 ts 1 ti 00 sub 43926) Received
'MNCC_REL_REQ' from MNCC in state 12 (DISCONNECT_IND)
<0001> gsm_04_08.c:2226 starting timer T308 with 10 seconds
<0001> gsm_04_08.c:1623 new state DISCONNECT_IND -> RELEASE_REQ
<0001> gsm_04_08.c:143 (bts 0 trx 0 ts 1 ti 00) Sending 'RELEASE' to MS.
<0001> gsm_04_08.c:3796 (bts 0 trx 0 ts 1 ti 08 sub 44680) Received
'MNCC_DISC_REQ' from MNCC in state 19 (RELEASE_REQ)
<0001> gsm_04_08.c:3804 Message unhandled at this state.
<0001> gsm_04_08.c:2226 starting timer T308 with 10 seconds
<0001> gsm_04_08.c:143 (bts 0 trx 0 ts 1 ti 80) Sending 'RELEASE' to MS.
<0001> gsm_04_08.c:2226 starting timer T308 with 10 seconds
<0001> gsm_04_08.c:143 (bts 0 trx 0 ts 1 ti 00) Sending 'RELEASE' to MS.
<0001> gsm_04_08.c:1685 (bts 0 trx 0 ts 1 ti 8 sub 44680) Sending
'MNCC_REL_CNF' to MNCC.
<0001> gsm_04_08.c:1623 new state RELEASE_REQ -> NULL
<0000> chan_alloc.c:486 (bts=0,trx=0,ts=1,ss=0) starting release sequence
<0004> abis_rsl.c:1221 (bts=0,trx=0,ts=1,ss=0) state ACTIVE -> RELEASE
REQUESTED
<0003> gsm_04_08_utils.c:251 Sending Channel Release: Chan: Number: 0 Type:
3
<0004> abis_rsl.c:767 (bts=0,trx=0,ts=1,ss=0) DEACTivate SACCH CMD
<0001> gsm_04_08.c:1685 (bts 0 trx 0 ts 1 ti 0 sub 43926) Sending
'MNCC_REL_CNF' to MNCC.
<0001> gsm_04_08.c:1623 new state RELEASE_REQ -> NULL
<0000> chan_alloc.c:486 (bts=0,trx=0,ts=1,ss=1) starting release sequence
<0004> abis_rsl.c:1221 (bts=0,trx=0,ts=1,ss=1) state ACTIVE -> RELEASE
REQUESTED
<0003> gsm_04_08_utils.c:251 Sending Channel Release: Chan: Number: 1 Type:
3

Meanwhile I will try to collect more debug logs..


P.S. I am doing pure GSM call, w/o SIP. Maybe call from MS to VoIP will be
more stable...

2017-05-11 15:59 GMT+03:00 Neels Hofmeyr <nhofmeyr at sysmocom.de>:

> Please, again, no-one should *ever* send image bitmaps of text screenshots
> to a
> mailing list!
>
> ~N
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.osmocom.org/pipermail/baseband-devel/attachments/20170511/2d3ac856/attachment-0001.html>


More information about the baseband-devel mailing list