Bug #1795
closedosmo-bts-trx: fails to assign second lchan on TCH/H TS
Added by neels over 7 years ago. Updated about 7 years ago.
100%
Description
With osmo-bts-trx and a TS configuration featuring TCH/H timeslots,
a call between two phones on the same TRX BTS does never succeed to
use the second lchan of a TCH/H timeslot.
(I do have general unreliability of osmo-trx in my setup but this error
appears consistently)
- First available TCH/H is ts=5, lchan=0 [0]
- Second available TCH/H is ts=5, lchan=1 [1]
But this apparently times out and then [2] - Third available TCH/H on ts=6, lchan=0 is actually used
[0] 20160809212237806 DRLL <0000> chan_alloc.c:342 (bts=0,trx=0,ts=5,pchan=TCH/H) Allocating lchan=0 as TCH_H 20160809212237806 DRSL <0004> abis_rsl.c:1705 (bts=0,trx=0,ts=5,ss=0) Activating ARFCN(868) SS(0) lctype TCH_H r=CALL ra=0x40 ta=1 20160809212237806 DRSL <0004> abis_rsl.c:539 (bts=0,trx=0,ts=5,pchan=TCH/H) Tx RSL Channel Activate with act_type=INITIAL 20160809212237806 DRSL <0004> abis_rsl.c:1105 (bts=0,trx=0,ts=5,ss=0) state NONE -> ACTIVATION REQUESTED 20160809212237806 DRSL <0004> abis_rsl.c:1434 (bts=0,trx=0,ts=5,ss=0) CHANNEL ACTIVATE ACK 20160809212237806 DRSL <0004> abis_rsl.c:1105 (bts=0,trx=0,ts=5,ss=0) state ACTIVATION REQUESTED -> ACTIVE 20160809212238175 DRLL <0000> abis_rsl.c:1893 (bts=0,trx=0,ts=5,ss=0) SAPI=0 ESTABLISH INDICATION 20160809212238175 DRLL <0000> gsm_04_08.c:3667 Dispatching 04.08 message, pdisc=5 20160809212238175 DMM <0002> gsm_04_08.c:987 <- CM SERVICE REQUEST serv_type=0x01 MI(TMSI)=2191222410 20160809212238183 DMM <0002> gsm_04_08_utils.c:681 -> CM SERVICE ACK 20160809212238500 DRLL <0000> abis_rsl.c:1893 (bts=0,trx=0,ts=5,ss=0) SAPI=0 DATA INDICATION 20160809212239700 DRLL <0000> abis_rsl.c:1893 (bts=0,trx=0,ts=5,ss=0) SAPI=0 DATA INDICATION 20160809212239700 DRR <0003> bsc_api.c:647 BSC: Passing unknown 04.08 RR message type 0x60 to MSC 20160809212239700 DRLL <0000> gsm_04_08.c:3667 Dispatching 04.08 message, pdisc=6 20160809212239700 DRR <0003> gsm_04_08.c:1281 MSC: Unimplemented GSM 04.08 RR msg type 0x60 20160809212239972 DRLL <0000> abis_rsl.c:1893 (bts=0,trx=0,ts=5,ss=0) SAPI=0 DATA INDICATION 20160809212240213 DRLL <0000> abis_rsl.c:1893 (bts=0,trx=0,ts=5,ss=0) SAPI=0 DATA INDICATION 20160809212240213 DRLL <0000> gsm_04_08.c:3667 Dispatching 04.08 message, pdisc=3 20160809212240214 DMSC <000a> bsc_api.c:402 Sending ChanModify for speech: SPEECH_V1 on channel TCH_H 20160809212240215 DMM <0002> gsm_subscriber.c:176 Subscriber 901990000000038 not paged yet. 20160809212240938 DRLL <0000> abis_rsl.c:1893 (bts=0,trx=0,ts=5,ss=0) SAPI=0 DATA INDICATION 20160809212240938 DRSL <0004> abis_rsl.c:2110 (bts=0,trx=0,ts=5,ss=0) IPAC_BIND speech_mode=0x13 RTP_PAYLOAD=96 20160809212240938 DRSL <0004> abis_rsl.c:1453 (bts=0,trx=0,ts=5,ss=0) CHANNEL MODE MODIFY ACK 20160809212240977 DRSL <0004> abis_rsl.c:2290 (bts=0,trx=0,ts=5,ss=0) IPAC_CRCX_ACK LOCAL_IP=127.0.0.1 LOCAL_PORT=23536 CON_ID=0 [1] 20160809212241451 DRLL <0000> chan_alloc.c:342 (bts=0,trx=0,ts=5,pchan=TCH/H) Allocating lchan=1 as TCH_H 20160809212241451 DRSL <0004> abis_rsl.c:1705 (bts=0,trx=0,ts=5,ss=1) Activating ARFCN(868) SS(1) lctype TCH_H r=PAGING ra=0x27 ta=2 20160809212241451 DRSL <0004> abis_rsl.c:539 (bts=0,trx=0,ts=5,pchan=TCH/H) Tx RSL Channel Activate with act_type=INITIAL 20160809212241451 DRSL <0004> abis_rsl.c:1105 (bts=0,trx=0,ts=5,ss=1) state NONE -> ACTIVATION REQUESTED 20160809212241451 DRSL <0004> abis_rsl.c:1434 (bts=0,trx=0,ts=5,ss=1) CHANNEL ACTIVATE ACK 20160809212241451 DRSL <0004> abis_rsl.c:1105 (bts=0,trx=0,ts=5,ss=1) state ACTIVATION REQUESTED -> ACTIVE [2] 20160809212243806 DRLL <0000> chan_alloc.c:342 (bts=0,trx=0,ts=6,pchan=TCH/H) Allocating lchan=0 as TCH_H 20160809212243806 DRSL <0004> abis_rsl.c:1705 (bts=0,trx=0,ts=6,ss=0) Activating ARFCN(868) SS(0) lctype TCH_H r=PAGING ra=0x27 ta=2 20160809212243806 DRSL <0004> abis_rsl.c:539 (bts=0,trx=0,ts=6,pchan=TCH/H) Tx RSL Channel Activate with act_type=INITIAL 20160809212243806 DRSL <0004> abis_rsl.c:1105 (bts=0,trx=0,ts=6,ss=0) state NONE -> ACTIVATION REQUESTED 20160809212243806 DRSL <0004> abis_rsl.c:1434 (bts=0,trx=0,ts=6,ss=0) CHANNEL ACTIVATE ACK 20160809212243806 DRSL <0004> abis_rsl.c:1105 (bts=0,trx=0,ts=6,ss=0) state ACTIVATION REQUESTED -> ACTIVE
So it seems TRX is not capable of using two lchans on one TCH/H timeslot.
Files
| osmo-bts.cfg | osmo-bts.cfg | 717 Bytes | OsmoBTS configuration | fixeria, 03/21/2017 03:54 PM | |
| openbsc.cfg | openbsc.cfg | 3.41 KB | OpenBSC configuration | fixeria, 03/21/2017 03:54 PM | |
| bad_tch_calypso.pcap.gz | bad_tch_calypso.pcap.gz | 3.55 KB | A-bis communication of CalypsoBTS based network | fixeria, 03/21/2017 04:54 PM | |
| bad_tch_umtrx.pcap.gz | bad_tch_umtrx.pcap.gz | 24.2 KB | A-bis communication of OsmoTRX based network | fixeria, 03/21/2017 04:54 PM | |
| bad_tch_ms_side.pcap.gz | bad_tch_ms_side.pcap.gz | 11.2 KB | MS side Um communication | fixeria, 03/21/2017 05:26 PM |
Related issues
Updated by msuraev over 7 years ago
- Related to Bug #1524: PACCH on the wrong timeslot added
Updated by msuraev over 7 years ago
Could be related to #1524 where changing TS order makes a difference.
Updated by msuraev about 7 years ago
- % Done changed from 0 to 10
Reproduced locally, the problem seems to be that despite repetitive paging (Rx RSL PAGING_CMD) osmo-bts-trx never receive back established indication (Fwd RLL msg EST_IND from LAPDm to A-bis) from phone if assignment was on the same TS. Why this happens is unclear yet.
At the bts side there are multitude of errors like:
<0006> gsm0503_coding.c:1848 tch_fr_decode(): error checking CRC8 for an HR frame
<0006> scheduler_trx.c:1278 Received bad TCH frame ending at fn=641452 for TCH/H(0)
<0006> gsm0503_coding.c:1848 tch_fr_decode(): error checking CRC8 for an HR frame
<0006> scheduler_trx.c:1278 Received bad TCH frame ending at fn=641530 for TCH/H(0)
<0006> gsm0503_coding.c:1826 tch_hr_decode(): error decoding FACCH frame (158/456 bits)
<0006> scheduler_trx.c:1278 Received bad TCH frame ending at fn=641534 for TCH/H(0)
<0006> gsm0503_coding.c:1848 tch_fr_decode(): error checking CRC8 for an HR frame
<0006> scheduler_trx.c:1278 Received bad TCH frame ending at fn=641539 for TCH/H(0)
<0006> gsm0503_coding.c:1826 tch_hr_decode(): error decoding FACCH frame (342/456 bits)
Also, sometimes, call just fails instead of being established on different TS - can't reproduce this reliably yet though.
Updated by fixeria about 7 years ago
Hi Max,
I just tested the configuration with only one TCH/H channel
on both UmTRX SDR (through OsmoTRX) and CalypsoBTS (two OsmocomBB
phones acting as BTS). In short, both lchans of TCH/H work fine
on CalypsoBTS, and I was able to make a call between two connected
subscribers and hear the voice ;)
On OsmoTRX I am getting similar problem as you mentioned above.
The only difference is that I have configured only one TCH/H and
disabled others.
CalypsoBTS call log output:
<0000> chan_alloc.c:352 (bts=0,trx=0,ts=1,pchan=TCH/H) Allocating lchan=0 as TCH_H <0004> abis_rsl.c:1822 (bts=0,trx=0,ts=1,ss=0) Activating ARFCN(103) SS(0) lctype TCH_H r=CALL ra=0x4d ta=1 <0004> abis_rsl.c:578 (bts=0,trx=0,ts=1,pchan=TCH/H) Tx RSL Channel Activate with act_type=INITIAL <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=1,ss=0) state NONE -> ACTIVATION REQUESTED <0004> abis_rsl.c:1545 (bts=0,trx=0,ts=1,ss=0) CHANNEL ACTIVATE ACK <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=1,ss=0) state ACTIVATION REQUESTED -> ACTIVE <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=1,ss=0) SAPI=0 ESTABLISH INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=5 <0002> gsm_04_08.c:998 <- CM SERVICE REQUEST serv_type=0x01 MI(TMSI)=3752106384 <0002> gsm_04_08_utils.c:650 -> CM SERVICE ACK <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=1,ss=0) SAPI=0 DATA INDICATION <0003> bsc_api.c:593 GPRS SUSPENSION REQUEST <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=1,ss=0) SAPI=0 DATA INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=3 <0001> gsm_04_08.c:3877 (bts 0 trx 0 ts 1 ti 8 sub 41700) Received 'SETUP' from MS in state 0 (NULL) <0001> gsm_04_08.c:3882 Unknown transaction ID 8, creating new trans. <0001> transaction.c:71 subscr=0xe07990, net=0xcc3cd0 <0001> gsm_04_08.c:1605 new state NULL -> INITIATED <0001> gsm_04_08.c:2285 Subscriber XXXXXXXXXXXXXXX (41700) sends SETUP to 900 <0001> gsm_04_08.c:1667 (bts 0 trx 0 ts 1 ti 8 sub 41700) Sending 'MNCC_SETUP_IND' to MNCC. <0001> gsm_04_08.c:3779 (bts 0 trx 0 ts 1 ti 08 sub 41700) Received 'MNCC_LCHAN_MODIFY' from MNCC in state 1 (INITIATED) <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:500 -> CHANNEL MODE MODIFY mode=0x41 <0001> gsm_04_08.c:3779 (bts 0 trx 0 ts 1 ti 08 sub 41700) Received 'MNCC_CALL_PROC_REQ' from MNCC in state 1 (INITIATED) <0001> gsm_04_08.c:1605 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:2049 queue tch_recv_mncc request (1) <0001> transaction.c:71 subscr=0xe222a0, net=0xcc3cd0 <0002> gsm_subscriber.c:190 Subscriber YYYYYYYYYYYYYYY not paged yet. <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=1,ss=0) SAPI=0 DATA INDICATION <0003> gsm_04_08_utils.c:525 CHANNEL MODE MODIFY ACK <0004> abis_rsl.c:2229 (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:1566 (bts=0,trx=0,ts=1,ss=0) CHANNEL MODE MODIFY ACK <0004> abis_rsl.c:2410 (bts=0,trx=0,ts=1,ss=0) IPAC_CRCX_ACK LOCAL_IP=127.0.0.1 LOCAL_PORT=25704 CON_ID=0 <0001> gsm_04_08.c:1880 pending tch_re cv_mncc request <0004> abis_rsl.c:2268 (bts=0,trx=0,ts=1,ss=0) 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:2420 (bts=0,trx=0,ts=1,ss=0) IPAC_MDCX_ACK LOCAL_IP=127.0.0.1 LOCAL_PORT=25704 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:1822 (bts=0,trx=0,ts=1,ss=1) Activating ARFCN(103) SS(1) lctype TCH_H r=PAGING ra=0x20 ta=1 <0004> abis_rsl.c:578 (bts=0,trx=0,ts=1,pchan=TCH/H) Tx RSL Channel Activate with act_type=INITIAL <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=1,ss=1) state NONE -> ACTIVATION REQUESTED <0004> abis_rsl.c:1545 (bts=0,trx=0,ts=1,ss=1) CHANNEL ACTIVATE ACK <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=1,ss=1) state ACTIVATION REQUESTED -> ACTIVE <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=1,ss=1) SAPI=0 ESTABLISH INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=6 <0003> gsm_04_08.c:1444 PAGING RESPONSE: MI(TMSI)=872893893 <0003> gsm_04_08.c:1477 <- Channel was requested by YYYYYYYYYYYYYYY <0001> gsm_04_08.c:1737 Paging subscr 900 succeeded! <0001> gsm_04_08.c:2208 starting timer T303 with 30 seconds <0001> gsm_04_08.c:1605 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:2012 (bts=0,trx=0,ts=1,ss=1) SAPI=0 DATA INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=3 <0001> gsm_04_08.c:3877 (bts 0 trx 0 ts 1 ti 0 sub 900) Received 'CALL_CONF' from MS in state 6 (CALL_PRESENT) <0001> gsm_04_08.c:1647 stopping pending timer T303 <0001> gsm_04_08.c:2208 starting timer T310 with 180 seconds <0001> gsm_04_08.c:1605 new state CALL_PRESENT -> MO_TERM_CALL_CONF <0001> gsm_04_08.c:1667 (bts 0 trx 0 ts 1 ti 0 sub 900) Sending 'MNCC_CALL_CONF_IND' to MNCC. <0001> gsm_04_08.c:3779 (bts 0 trx 0 ts 1 ti 00 sub 900) 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:500 -> CHANNEL MODE MODIFY mode=0x41 <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=1,ss=1) SAPI=0 DATA INDICATION <0003> gsm_04_08_utils.c:525 CHANNEL MODE MODIFY ACK <0004> abis_rsl.c:2229 (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:1566 (bts=0,trx=0,ts=1,ss=1) CHANNEL MODE MODIFY ACK <0004> abis_rsl.c:2410 (bts=0,trx=0,ts=1,ss=1) IPAC_CRCX_ACK LOCAL_IP=127.0.0.1 LOCAL_PORT=17656 CON_ID=0 <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=1,ss=1) SAPI=0 DATA INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=3 <0001> gsm_04_08.c:3877 (bts 0 trx 0 ts 1 ti 0 sub 900) Received 'ALERTING' from MS in state 9 (MO_TERM_CALL_CONF) <0001> gsm_04_08.c:1647 stopping pending timer T310 <0001> gsm_04_08.c:2208 starting timer T301 with 180 seconds <0001> gsm_04_08.c:1605 new state MO_TERM_CALL_CONF -> CALL_RECEIVED <0001> gsm_04_08.c:1667 (bts 0 trx 0 ts 1 ti 0 sub 900) Sending 'MNCC_ALERT_IND' to MNCC. <0001> gsm_04_08.c:3779 (bts 0 trx 0 ts 1 ti 08 sub 41700) Received 'MNCC_ALERT_REQ' from MNCC in state 3 (MO_CALL_PROC) <0001> gsm_04_08.c:1605 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:2012 (bts=0,trx=0,ts=1,ss=1) SAPI=0 DATA INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=3 <0001> gsm_04_08.c:3877 (bts 0 trx 0 ts 1 ti 0 sub 900) Received 'CONNECT' from MS in state 7 (CALL_RECEIVED) <0001> gsm_04_08.c:1647 stopping pending timer T301 <0001> gsm_04_08.c:1605 new state CALL_RECEIVED -> CONNECT_REQUEST <0001> gsm_04_08.c:1667 (bts 0 trx 0 ts 1 ti 0 sub 900) Sending 'MNCC_SETUP_CNF' to MNCC. <0001> gsm_04_08.c:3779 (bts 0 trx 0 ts 1 ti 00 sub 900) Received 'MNCC_SETUP_COMPL_REQ' from MNCC in state 8 (CONNECT_REQUEST) <0001> gsm_04_08.c:1605 new state CONNECT_REQUEST -> ACTIVE <0001> gsm_04_08.c:143 (bts 0 trx 0 ts 1 ti 00) Sending 'CONNECT_ACK' to MS. <0004> abis_rsl.c:2268 (bts=0,trx=0,ts=1,ss=1) IPAC_MDCX IP=127.0.0.1 PORT=30004 RTP_PAYLOAD=98 RTP_PAYLOAD2=0 CONN_ID=0 speech_mode=0x05 <0001> gsm_04_08.c:3779 (bts 0 trx 0 ts 1 ti 08 sub 41700) Received 'MNCC_SETUP_RSP' from MNCC in state 4 (CALL_DELIVERED) <0001> gsm_04_08.c:2208 starting timer T313 with 30 seconds <0001> gsm_04_08.c:1605 new state CALL_DELIVERED -> CONNECT_IND <0001> gsm_04_08.c:143 (bts 0 trx 0 ts 1 ti 80) Sending 'CONNECT' to MS. <0004> abis_rsl.c:2420 (bts=0,trx=0,ts=1,ss=1) IPAC_MDCX_ACK LOCAL_IP=127.0.0.1 LOCAL_PORT=17656 CON_ID=0 <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=1,ss=0) SAPI=0 DATA INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=3 <0001> gsm_04_08.c:3877 (bts 0 trx 0 ts 1 ti 8 sub 41700) Received 'CONNECT_ACK' from MS in state 28 (CONNECT_IND) <0001> gsm_04_08.c:1647 stopping pending timer T313 <0001> gsm_04_08.c:1605 new state CONNECT_IND -> ACTIVE <0001> gsm_04_08.c:1667 (bts 0 trx 0 ts 1 ti 8 sub 41700) Sending 'MNCC_SETUP_COMPL_IND' to MNCC. <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=1,ss=0) SAPI=0 DATA INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=3 <0001> gsm_04_08.c:3877 (bts 0 trx 0 ts 1 ti 8 sub 41700) Received 'DISCONNECT' from MS in state 10 (ACTIVE) <0001> gsm_04_08.c:1605 new state ACTIVE -> DISCONNECT_IND <0001> gsm_04_08.c:1667 (bts 0 trx 0 ts 1 ti 8 sub 41700) Sending 'MNCC_DISC_IND' to MNCC. <0001> gsm_04_08.c:3779 (bts 0 trx 0 ts 1 ti 08 sub 41700) Received 'MNCC_REL_REQ' from MNCC in state 12 (DISCONNECT_IND) <0001> gsm_04_08.c:2208 starting timer T308 with 10 seconds <0001> gsm_04_08.c:1605 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:3779 (bts 0 trx 0 ts 1 ti 00 sub 900) Received 'MNCC_DISC_REQ' from MNCC in state 10 (ACTIVE) <0001> gsm_04_08.c:2208 starting timer T306 with 30 seconds <0001> gsm_04_08.c:1605 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:2012 (bts=0,trx=0,ts=1,ss=0) SAPI=0 DATA INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=3 <0001> gsm_04_08.c:3877 (bts 0 trx 0 ts 1 ti 8 sub 41700) Received 'RELEASE_COMPL' from MS in state 19 (RELEASE_REQ) <0001> gsm_04_08.c:1647 stopping pending timer T308 <0001> gsm_04_08.c:1667 (bts 0 trx 0 ts 1 ti 8 sub 41700) Sending 'MNCC_REL_CNF' to MNCC. <0001> gsm_04_08.c:1605 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:1188 (bts=0,trx=0,ts=1,ss=0) state ACTIVE -> RELEASE REQUESTED <0003> gsm_04_08_utils.c:239 Sending Channel Release: Chan: Number: 0 Type: 3 <0004> abis_rsl.c:760 (bts=0,trx=0,ts=1,ss=0) DEACTivate SACCH CMD <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=1,ss=0) SAPI=0 RELEASE INDICATION <0004> abis_rsl.c:1673 (bts=0,trx=0,ts=1,ss=0) T3111 expired: releasing RF Channel <0004> abis_rsl.c:852 (bts=0,trx=0,ts=1,ss=0) RF Channel Release <0004> abis_rsl.c:2429 (bts=0,trx=0,ts=1,ss=0) IPAC_DLCX_IND <0004> abis_rsl.c:923 (bts=0,trx=0,ts=1,ss=0) RF CHANNEL RELEASE ACK <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=1,ss=0) state RELEASE REQUESTED -> NONE <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=1,ss=1) SAPI=0 DATA INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=3 <0001> gsm_04_08.c:3877 (bts 0 trx 0 ts 1 ti 0 sub 900) Received 'RELEASE' from MS in state 12 (DISCONNECT_IND) <0001> gsm_04_08.c:1647 stopping pending timer T306 <0001> gsm_04_08.c:143 (bts 0 trx 0 ts 1 ti 00) Sending 'RELEASE_COMPL' to MS. <0001> gsm_04_08.c:1667 (bts 0 trx 0 ts 1 ti 0 sub 900) Sending 'MNCC_REL_IND' to MNCC. <0001> gsm_04_08.c:1605 new state DISCONNECT_IND -> NULL <0000> chan_alloc.c:486 (bts=0,trx=0,ts=1,ss=1) starting release sequence <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=1,ss=1) state ACTIVE -> RELEASE REQUESTED <0003> gsm_04_08_utils.c:239 Sending Channel Release: Chan: Number: 1 Type: 3 <0004> abis_rsl.c:760 (bts=0,trx=0,ts=1,ss=1) DEACTivate SACCH CMD <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=1,ss=1) SAPI=0 RELEASE INDICATION <0004> abis_rsl.c:1673 (bts=0,trx=0,ts=1,ss=1) T3111 expired: releasing RF Channel <0004> abis_rsl.c:852 (bts=0,trx=0,ts=1,ss=1) RF Channel Release <0004> abis_rsl.c:2429 (bts=0,trx=0,ts=1,ss=1) IPAC_DLCX_IND <0004> abis_rsl.c:923 (bts=0,trx=0,ts=1,ss=1) RF CHANNEL RELEASE ACK <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=1,ss=1) state RELEASE REQUESTED -> NONE
Updated by msuraev about 7 years ago
fixeria wrote:
In short, both lchans of TCH/H work fine
on CalypsoBTS, and I was able to make a call between two connected
subscribers and hear the voice ;)
Curious, could you share more details on your calypsoBTS setup - configs, branches etc? If I understand this correctly, the only difference in this setup is replacement of osmo-trx with transceiver app from OsmocomBB. In this case the error is somewhere inside osmo-trx.
Updated by fixeria about 7 years ago
- File osmo-bts.cfg osmo-bts.cfg added
- File openbsc.cfg openbsc.cfg added
- File bad_tch_umtrx.pcap.gz bad_tch_umtrx.pcap.gz added
- File bad_tch_calypso.pcap.gz bad_tch_calypso.pcap.gz added
- File bad_tch_ms_side.pcap.gz bad_tch_ms_side.pcap.gz added
Max wrote:
Curious, could you share more details on your calypsoBTS setup - configs, branches etc?
Of course, sorry for late answer.
CONFIGURATION¶
Both OpenBSC and OsmoBTS configuration files are attached to this message.
In case of CalypsoBTS there are the following changes:
diff osmo-bts.cfg
timing-advance-loop - settsc + setbsic gsmtap-sapi ccch
diff openbsc.cfg
timeslot 1
- phys_chan_config SDCCH8
+ phys_chan_config TCH/H
hopping enabled 0
GIT INFO¶
All software was compiled from master.
libosmocore: b14caa0ab9c6b8b8671171a238ab70eb66cf5bbe
libosmo-abis: beb10ef02a10d73537a97f6f21aad36664c9b266
libosmo-netif: 5fd93e02f818aecfc73db66e8064858442122959
libosmo-dsp: e82886ad0e13bb012e4a244df2ce6d84cd277763
openbsc: 6d804b1a7e375213cb4b3e437c2b9b8c68872164
osmo-bts: a1b891aab4a250ef12ed6c1cd2a331a272b4d65c
osmo-trx: 2dee3e996e777b67aa3185f7456c041765f0d71f
sofia-sip-1.12.11
libortp-dev 3.6.1-2.1build2
libortp9:amd64 3.6.1-2.1build2
libopencore-amrnb0:amd64 0.1.3-2ubuntu1
libopencore-amrwb0:amd64 0.1.3-2ubuntu1
OpenBSC and OsmoBTS log output¶
UmTRX through OsmoTRX transceiver:¶
// Subscriber #1 initiates an outgoing call on TS2/SS0 <0000> chan_alloc.c:352 (bts=0,trx=0,ts=2,pchan=TCH/H) Allocating lchan=0 as TCH_H <0004> abis_rsl.c:1822 (bts=0,trx=0,ts=2,ss=0) Activating ARFCN(103) SS(0) lctype TCH_H r=CALL ra=0x40 ta=1 <0004> abis_rsl.c:578 (bts=0,trx=0,ts=2,pchan=TCH/H) Tx RSL Channel Activate with act_type=INITIAL <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=2,ss=0) state NONE -> ACTIVATION REQUESTED <0004> abis_rsl.c:1545 (bts=0,trx=0,ts=2,ss=0) CHANNEL ACTIVATE ACK <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=2,ss=0) state ACTIVATION REQUESTED -> ACTIVE <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=2,ss=0) SAPI=0 ESTABLISH INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=5 <0002> gsm_04_08.c:998 <- CM SERVICE REQUEST serv_type=0x01 MI(TMSI)=3451168378 <0002> gsm_04_08_utils.c:650 -> CM SERVICE ACK <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=2,ss=0) SAPI=0 DATA INDICATION <0003> bsc_api.c:593 GPRS SUSPENSION REQUEST <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=2,ss=0) SAPI=0 DATA INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=3 <0001> gsm_04_08.c:3877 (bts 0 trx 0 ts 2 ti 8 sub 41700) Received 'SETUP' from MS in state 0 (NULL) <0001> gsm_04_08.c:3882 Unknown transaction ID 8, creating new trans. <0001> transaction.c:71 subscr=0x1b79bc0, net=0x1a1bcd0 <0001> gsm_04_08.c:1605 new state NULL -> INITIATED <0001> gsm_04_08.c:2285 Subscriber XXXXXXXXXXXXXXX (41700) sends SETUP to 900 <0001> gsm_04_08.c:1667 (bts 0 trx 0 ts 2 ti 8 sub 41700) Sending 'MNCC_SETUP_IND' to MNCC. <0001> gsm_04_08.c:3779 (bts 0 trx 0 ts 2 ti 08 sub 41700) Received 'MNCC_LCHAN_MODIFY' from MNCC in state 1 (INITIATED) <000a> bsc_api.c:404 Sending (bts=0,trx=0,ts=2,ss=0) ChanModify for speech: SPEECH_AMR on channel TCH_H <0003> gsm_04_08_utils.c:500 -> CHANNEL MODE MODIFY mode=0x41 <0001> gsm_04_08.c:3779 (bts 0 trx 0 ts 2 ti 08 sub 41700) Received 'MNCC_CALL_PROC_REQ' from MNCC in state 1 (INITIATED) <0001> gsm_04_08.c:1605 new state INITIATED -> MO_CALL_PROC <0001> gsm_04_08.c:143 (bts 0 trx 0 ts 2 ti 80) Sending 'CALL_PROC' to MS. <0001> gsm_04_08.c:2049 queue tch_recv_mncc request (1) <0001> transaction.c:71 subscr=0x1b5c370, net=0x1a1bcd0 <0002> gsm_subscriber.c:190 Subscriber YYYYYYYYYYYYYYY not paged yet. <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=2,ss=0) SAPI=0 DATA INDICATION <0003> gsm_04_08_utils.c:525 CHANNEL MODE MODIFY ACK <0004> abis_rsl.c:2229 (bts=0,trx=0,ts=2,ss=0) IPAC_BIND speech_mode=0x15 RTP_PAYLOAD=98 <0003> osmo_msc.c:76 MSC assign complete (do nothing). <0004> abis_rsl.c:1566 (bts=0,trx=0,ts=2,ss=0) CHANNEL MODE MODIFY ACK <0004> abis_rsl.c:2410 (bts=0,trx=0,ts=2,ss=0) IPAC_CRCX_ACK LOCAL_IP=127.0.0.1 LOCAL_PORT=17674 CON_ID=0 <0001> gsm_04_08.c:1880 pending tch_recv_mncc request <0004> abis_rsl.c:2268 (bts=0,trx=0,ts=2,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:2420 (bts=0,trx=0,ts=2,ss=0) IPAC_MDCX_ACK LOCAL_IP=127.0.0.1 LOCAL_PORT=17674 CON_ID=0 // The network allocates TS2/SS1 for subscriber #2 // NOTE: there is no "ESTABLISH INDICATION" <0000> chan_alloc.c:352 (bts=0,trx=0,ts=2,pchan=TCH/H) Allocating lchan=1 as TCH_H <0004> abis_rsl.c:1822 (bts=0,trx=0,ts=2,ss=1) Activating ARFCN(103) SS(1) lctype TCH_H r=PAGING ra=0x2b ta=1 <0004> abis_rsl.c:578 (bts=0,trx=0,ts=2,pchan=TCH/H) Tx RSL Channel Activate with act_type=INITIAL <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=2,ss=1) state NONE -> ACTIVATION REQUESTED <0004> abis_rsl.c:1545 (bts=0,trx=0,ts=2,ss=1) CHANNEL ACTIVATE ACK <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=2,ss=1) state ACTIVATION REQUESTED -> ACTIVE // The network allocates TS3/SS0 for subscriber #2 <0000> chan_alloc.c:352 (bts=0,trx=0,ts=3,pchan=TCH/H) Allocating lchan=0 as TCH_H <0004> abis_rsl.c:1822 (bts=0,trx=0,ts=3,ss=0) Activating ARFCN(103) SS(0) lctype TCH_H r=PAGING ra=0x24 ta=1 <0004> abis_rsl.c:578 (bts=0,trx=0,ts=3,pchan=TCH/H) Tx RSL Channel Activate with act_type=INITIAL <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=3,ss=0) state NONE -> ACTIVATION REQUESTED <0004> abis_rsl.c:1545 (bts=0,trx=0,ts=3,ss=0) CHANNEL ACTIVATE ACK <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=3,ss=0) state ACTIVATION REQUESTED -> ACTIVE <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=3,ss=0) SAPI=0 ESTABLISH INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=6 <0003> gsm_04_08.c:1444 PAGING RESPONSE: MI(TMSI)=2229387159 <0003> gsm_04_08.c:1477 <- Channel was requested by YYYYYYYYYYYYYYY <0001> gsm_04_08.c:1737 Paging subscr 900 succeeded! <0001> gsm_04_08.c:2208 starting timer T303 with 30 seconds <0001> gsm_04_08.c:1605 new state NULL -> CALL_PRESENT <0001> gsm_04_08.c:143 (bts 0 trx 0 ts 3 ti 00) Sending 'SETUP' to MS. <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=3,ss=0) SAPI=0 DATA INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=3 <0001> gsm_04_08.c:3877 (bts 0 trx 0 ts 3 ti 0 sub 900) Received 'CALL_CONF' from MS in state 6 (CALL_PRESENT) <0001> gsm_04_08.c:1647 stopping pending timer T303 <0001> gsm_04_08.c:2208 starting timer T310 with 180 seconds <0001> gsm_04_08.c:1605 new state CALL_PRESENT -> MO_TERM_CALL_CONF <0001> gsm_04_08.c:1667 (bts 0 trx 0 ts 3 ti 0 sub 900) Sending 'MNCC_CALL_CONF_IND' to MNCC. <0001> gsm_04_08.c:3779 (bts 0 trx 0 ts 3 ti 00 sub 900) Received 'MNCC_LCHAN_MODIFY' from MNCC in state 9 (MO_TERM_CALL_CONF) <000a> bsc_api.c:404 Sending (bts=0,trx=0,ts=3,ss=0) ChanModify for speech: SPEECH_AMR on channel TCH_H <0003> gsm_04_08_utils.c:500 -> CHANNEL MODE MODIFY mode=0x41 <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=3,ss=0) SAPI=0 DATA INDICATION <0003> gsm_04_08_utils.c:525 CHANNEL MODE MODIFY ACK <0004> abis_rsl.c:2229 (bts=0,trx=0,ts=3,ss=0) IPAC_BIND speech_mode=0x15 RTP_PAYLOAD=98 <0003> osmo_msc.c:76 MSC assign complete (do nothing). <0004> abis_rsl.c:1566 (bts=0,trx=0,ts=3,ss=0) CHANNEL MODE MODIFY ACK <0004> abis_rsl.c:2410 (bts=0,trx=0,ts=3,ss=0) IPAC_CRCX_ACK LOCAL_IP=127.0.0.1 LOCAL_PORT=48012 CON_ID=0 <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=3,ss=0) SAPI=0 DATA INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=3 <0001> gsm_04_08.c:3877 (bts 0 trx 0 ts 3 ti 0 sub 900) Received 'ALERTING' from MS in state 9 (MO_TERM_CALL_CONF) <0001> gsm_04_08.c:1647 stopping pending timer T310 <0001> gsm_04_08.c:2208 starting timer T301 with 180 seconds <0001> gsm_04_08.c:1605 new state MO_TERM_CALL_CONF -> CALL_RECEIVED <0001> gsm_04_08.c:1667 (bts 0 trx 0 ts 3 ti 0 sub 900) Sending 'MNCC_ALERT_IND' to MNCC. <0001> gsm_04_08.c:3779 (bts 0 trx 0 ts 2 ti 08 sub 41700) Received 'MNCC_ALERT_REQ' from MNCC in state 3 (MO_CALL_PROC) <0001> gsm_04_08.c:1605 new state MO_CALL_PROC -> CALL_DELIVERED <0001> gsm_04_08.c:143 (bts 0 trx 0 ts 2 ti 80) Sending 'ALERTING' to MS. <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=3,ss=0) SAPI=0 DATA INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=3 <0001> gsm_04_08.c:3877 (bts 0 trx 0 ts 3 ti 0 sub 900) Received 'CONNECT' from MS in state 7 (CALL_RECEIVED) <0001> gsm_04_08.c:1647 stopping pending timer T301 <0001> gsm_04_08.c:1605 new state CALL_RECEIVED -> CONNECT_REQUEST <0001> gsm_04_08.c:1667 (bts 0 trx 0 ts 3 ti 0 sub 900) Sending 'MNCC_SETUP_CNF' to MNCC. <0001> gsm_04_08.c:3779 (bts 0 trx 0 ts 3 ti 00 sub 900) Received 'MNCC_SETUP_COMPL_REQ' from MNCC in state 8 (CONNECT_REQUEST) <0001> gsm_04_08.c:1605 new state CONNECT_REQUEST -> ACTIVE <0001> gsm_04_08.c:143 (bts 0 trx 0 ts 3 ti 00) Sending 'CONNECT_ACK' to MS. <0004> abis_rsl.c:2268 (bts=0,trx=0,ts=3,ss=0) IPAC_MDCX IP=127.0.0.1 PORT=30002 RTP_PAYLOAD=98 RTP_PAYLOAD2=0 CONN_ID=0 speech_mode=0x05 <0001> gsm_04_08.c:3779 (bts 0 trx 0 ts 2 ti 08 sub 41700) Received 'MNCC_SETUP_RSP' from MNCC in state 4 (CALL_DELIVERED) <0001> gsm_04_08.c:2208 starting timer T313 with 30 seconds <0001> gsm_04_08.c:1605 new state CALL_DELIVERED -> CONNECT_IND <0001> gsm_04_08.c:143 (bts 0 trx 0 ts 2 ti 80) Sending 'CONNECT' to MS. <0004> abis_rsl.c:2420 (bts=0,trx=0,ts=3,ss=0) IPAC_MDCX_ACK LOCAL_IP=127.0.0.1 LOCAL_PORT=48012 CON_ID=0 <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=2,ss=0) SAPI=0 DATA INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=3 <0001> gsm_04_08.c:3877 (bts 0 trx 0 ts 2 ti 8 sub 41700) Received 'CONNECT_ACK' from MS in state 28 (CONNECT_IND) <0001> gsm_04_08.c:1647 stopping pending timer T313 <0001> gsm_04_08.c:1605 new state CONNECT_IND -> ACTIVE <0001> gsm_04_08.c:1667 (bts 0 trx 0 ts 2 ti 8 sub 41700) Sending 'MNCC_SETUP_COMPL_IND' to MNCC. // Paging Response wasn't received on TS2/SS1, so T3101 expired <0004> abis_rsl.c:1663 (bts=0,trx=0,ts=2,ss=1) T3101 expired: no response to IMMEDIATE ASSIGN <0004> abis_rsl.c:850 (bts=0,trx=0,ts=2,ss=1) RF Channel Release due to error: 1 <0004> abis_rsl.c:760 (bts=0,trx=0,ts=2,ss=1) DEACTivate SACCH CMD <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=2,ss=1) state ACTIVE -> RELEASE DUE ERROR <0004> abis_rsl.c:923 (bts=0,trx=0,ts=2,ss=1) RF CHANNEL RELEASE ACK <0004> abis_rsl.c:809 (bts=0,trx=0,ts=2,ss=1) is back in operation. <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=2,ss=1) state RELEASE DUE ERROR -> NONE <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=2,ss=0) SAPI=0 DATA INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=3 <0001> gsm_04_08.c:3877 (bts 0 trx 0 ts 2 ti 8 sub 41700) Received 'DISCONNECT' from MS in state 10 (ACTIVE) <0001> gsm_04_08.c:1605 new state ACTIVE -> DISCONNECT_IND <0001> gsm_04_08.c:1667 (bts 0 trx 0 ts 2 ti 8 sub 41700) Sending 'MNCC_DISC_IND' to MNCC. <0001> gsm_04_08.c:3779 (bts 0 trx 0 ts 2 ti 08 sub 41700) Received 'MNCC_REL_REQ' from MNCC in state 12 (DISCONNECT_IND) <0001> gsm_04_08.c:2208 starting timer T308 with 10 seconds <0001> gsm_04_08.c:1605 new state DISCONNECT_IND -> RELEASE_REQ <0001> gsm_04_08.c:143 (bts 0 trx 0 ts 2 ti 80) Sending 'RELEASE' to MS. <0001> gsm_04_08.c:3779 (bts 0 trx 0 ts 3 ti 00 sub 900) Received 'MNCC_DISC_REQ' from MNCC in state 10 (ACTIVE) <0001> gsm_04_08.c:2208 starting timer T306 with 30 seconds <0001> gsm_04_08.c:1605 new state ACTIVE -> DISCONNECT_IND <0001> gsm_04_08.c:143 (bts 0 trx 0 ts 3 ti 00) Sending 'DISCONNECT' to MS. <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=2,ss=0) SAPI=0 DATA INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=3 <0001> gsm_04_08.c:3877 (bts 0 trx 0 ts 2 ti 8 sub 41700) Received 'RELEASE_COMPL' from MS in state 19 (RELEASE_REQ) <0001> gsm_04_08.c:1647 stopping pending timer T308 <0001> gsm_04_08.c:1667 (bts 0 trx 0 ts 2 ti 8 sub 41700) Sending 'MNCC_REL_CNF' to MNCC. <0001> gsm_04_08.c:1605 new state RELEASE_REQ -> NULL <0000> chan_alloc.c:486 (bts=0,trx=0,ts=2,ss=0) starting release sequence <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=2,ss=0) state ACTIVE -> RELEASE REQUESTED <0003> gsm_04_08_utils.c:239 Sending Channel Release: Chan: Number: 0 Type: 3 <0004> abis_rsl.c:760 (bts=0,trx=0,ts=2,ss=0) DEACTivate SACCH CMD <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=2,ss=0) SAPI=0 RELEASE INDICATION <0004> abis_rsl.c:1673 (bts=0,trx=0,ts=2,ss=0) T3111 expired: releasing RF Channel <0004> abis_rsl.c:852 (bts=0,trx=0,ts=2,ss=0) RF Channel Release <0004> abis_rsl.c:2429 (bts=0,trx=0,ts=2,ss=0) IPAC_DLCX_IND <0004> abis_rsl.c:923 (bts=0,trx=0,ts=2,ss=0) RF CHANNEL RELEASE ACK <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=2,ss=0) state RELEASE REQUESTED -> NONE <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=3,ss=0) SAPI=0 DATA INDICATION <0000> gsm_04_08.c:3983 Dispatching 04.08 message, pdisc=3 <0001> gsm_04_08.c:3877 (bts 0 trx 0 ts 3 ti 0 sub 900) Received 'RELEASE' from MS in state 12 (DISCONNECT_IND) <0001> gsm_04_08.c:1647 stopping pending timer T306 <0001> gsm_04_08.c:143 (bts 0 trx 0 ts 3 ti 00) Sending 'RELEASE_COMPL' to MS. <0001> gsm_04_08.c:1667 (bts 0 trx 0 ts 3 ti 0 sub 900) Sending 'MNCC_REL_IND' to MNCC. <0001> gsm_04_08.c:1605 new state DISCONNECT_IND -> NULL <0000> chan_alloc.c:486 (bts=0,trx=0,ts=3,ss=0) starting release sequence <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=3,ss=0) state ACTIVE -> RELEASE REQUESTED <0003> gsm_04_08_utils.c:239 Sending Channel Release: Chan: Number: 0 Type: 3 <0004> abis_rsl.c:760 (bts=0,trx=0,ts=3,ss=0) DEACTivate SACCH CMD <0004> abis_rsl.c:1389 (bts=0,trx=0,ts=3,ss=0): MEAS RES for inactive channel <0006> gsm_04_08.c:3595 TCH frame for non-existing trans <0000> abis_rsl.c:2012 (bts=0,trx=0,ts=3,ss=0) SAPI=0 RELEASE INDICATION <0004> abis_rsl.c:1673 (bts=0,trx=0,ts=3,ss=0) T3111 expired: releasing RF Channel <0004> abis_rsl.c:852 (bts=0,trx=0,ts=3,ss=0) RF Channel Release <0004> abis_rsl.c:2429 (bts=0,trx=0,ts=3,ss=0) IPAC_DLCX_IND <0004> abis_rsl.c:923 (bts=0,trx=0,ts=3,ss=0) RF CHANNEL RELEASE ACK <0004> abis_rsl.c:1188 (bts=0,trx=0,ts=3,ss=0) state RELEASE REQUESTED -> NONE
Another look from another side¶
Now let's have a look, what's happening on MS side.
Both subscribers were registered in the test network:
- Subscriber #1 - regular phone (initiates call)
- Subscriber #2 - OsmocomBB mobile application (accepts call)
1. Subscriber #1 requests a channel (sending RACH)
2. Network allocates a new channel on TS2/SS0 as TCH/H and sends an IMM ASS
3. Subscriber #1 switches to TS2/SS0 and requests the voice call service to #2
4. Network periodically sends Paging Request to subscriber #2
5. Subscriber #2 sees the Paging Request and requests a new channel (sending RACH)
6. Network allocates a new channel on TS2/SS1 and sends an IMM ASS
7. Subscriber #2 switches to TS2/SS1, and sends Paging Response
8. BUT! Network doesn't response to the Paging Response, and still sends Paging Requests...
9. Subscriber #2 switches back to CCCH TS0, because some timer getting expired
10. Subscriber #2 still sees Paging Requests, and requests a new channel (sending RACH)
11. Network allocates a new channel on TS3/SS0 and sends an IMM ASS
12. Subscriber #2 switches to TS3/SS0, and sends Paging Response
13. Now the network handles the Paging Response and the phone is rings
14. Meanwhile, T3101 expires for TS2/SS1 because Paging Response wasn't reached the BSC
15. Network deactivates TS2/SS1
So, the problem is that the OsmoTRX based network doesn't handle incoming data on the second lchan.
Please also see some network captures attached.
Updated by fixeria about 7 years ago
- Status changed from Stalled to In Progress
- Priority changed from Normal to High
- % Done changed from 10 to 90
Dear Max,
I just managed to make both lchans of a single TS work.
The problem is that OsmoBTS sends the "SETSLOT N 2" instead of "SETSLOT N 3".
Please see http://git.osmocom.org/osmo-trx/tree/Transceiver52M/Transceiver.h#n125
In case of ChannelCombination II, OsmoTRX ignores UL data on TSN/SS1, what we
can clearly see in the MS side traffic dump. So, I did a simple hack in OsmoTRX
source code, replacing 2 by 3, and the miracle happened ;)
Now we need to figure out, is it a bug of OsmoTRX or OsmoBTS.
Updated by neels about 7 years ago
fixeria wrote:
Now we need to figure out, is it a bug of OsmoTRX or OsmoBTS.
Excellent! Nice catch.
Take a look at http://git.osmocom.org/osmo-bts/tree/src/osmo-bts-trx/l1_if.c#n47
which sets TCH_H to 2,
which is assigned to slottype at http://git.osmocom.org/osmo-bts/tree/src/osmo-bts-trx/l1_if.c#n431
Is the issue fixed when using 3 instead of 2 in transceiver_chan_types[]?
Should it use two or three dynamically, depending on how many lchans are in use?
(Besides, there should not be magic numbers in that transceiver_chan_types array,
we should probably use defined constants instead ... somehow.)
Updated by fixeria about 7 years ago
Neels wrote:
Take a look at http://git.osmocom.org/osmo-bts/tree/src/osmo-bts-trx/l1_if.c#n47
which sets TCH_H to 2,
which is assigned to slottype at http://git.osmocom.org/osmo-bts/tree/src/osmo-bts-trx/l1_if.c#n431
Thanks, exactly what I was looking for.
Is the issue fixed when using 3 instead of 2 in transceiver_chan_types[]?
Yes, but I did the hack on the OsmoTRX side. So, let me some time to try with OsmoBTS.
Should it use two or three dynamically, depending on how many lchans are in use?
Good question. What kind of difference between TCH/F and TCH/H in II the mode?
Regarding to the way of resolving this issue: I sugget to change the hardcored magic
number to the III. What do you think?
Updated by ipse about 7 years ago
Ok, I'm glad that my suggestion about channel types on osmo-trx has worked out.
For the reference, a full list of channel combination types is in GSM 05.02 section "6.4.1 Permitted channel combinations onto a basic physical channel": http://www.qtc.jp/3GPP/Specs/GSM_GERAN/0502-8b0.pdf
It clearly states that channel combination II is only for one TCH/H channel and combination III is two TCH/H channels, osmo-trx behavior is correct and it's osmo-bts which should be fixed:
ii) TCH/H(0,1) + FACCH/H(0,1) + SACCH/TH
iii) TCH/H(0,0) + FACCH/H(0,1) + SACCH/TH + TCH/H(1,1)
That said, you should test with a Calypso based setup first to make sure Calypso will accept channel combination III just as it works with channel combination II right now. Otherwise we'll have to somehow distinguish between Calypso and a proper SDR based osmo-trx.
The reason for combination II is that it saves a bit of CPU by disabling Rx burst detection on SS1. Also when used on C1..n it may flag that transmission of downlink bursts on SS1 is turned off to reduce interference and save some power. That said, in the current implementation osmo-trx transmits only those bursts which are sent by osmo-bts, so the latter concern is not valid for osmo-trx - this should be handled by osmo-bts itself.
So ideally we should start with combination II when we have only one TCH/H call on a slot and dynamically switch to combination III when a second channel is allocated, or to channel combination XXIV when we want to use SS1 for PDTCH/H. But changing to channel combination III will solve the issue in short terms (if we don't want to use PDTCH/H) in exchange to a slight increase of CPU usage in under-loaded situations.
That said, we should introduce much more dynamic channel switching between osmo-bts and osmo-trx, because right now all channels are configured on start and thus Rx burst detection is always active on all timeslots, which is far from optimal from CPU utilization perspective. We should probably create a separate ticket for that.
We also should add all 24 channel combinations to osmo-trx, because right now it supports only the first 13. Then these channel combinations should be also added to osmo-bts-trx which I believe lack those and thus lacks support for SMSCB for example. A separate ticket as well I assume.
Updated by fixeria about 7 years ago
Hi,
That said, you should test with a Calypso based setup first to make sure
Calypso will accept channel combination III just as it works with channel
combination II right now. Otherwise we'll have to somehow distinguish between
Calypso and a proper SDR based osmo-trx.
Yeah, just tested - works fine as with II. Both SS0 and SS1 are available.
The reason for combination II is that it saves a bit of CPU by disabling Rx
burst detection on SS1. Also when used on C1..n it may flag that transmission
of downlink bursts on SS1 is turned off to reduce interference and save some power.
That said, in the current implementation osmo-trx transmits only those bursts which
are sent by osmo-bts, so the latter concern is not valid for osmo-trx - this should
be handled by osmo-bts itself.
Great explanation, thanks!
My suggestion is to change the II to III for now, until dynamic II <-> III switching
is implemented. The patch is very simple and ready to be sent to the Gerrit.
Updated by ipse about 7 years ago
fixeria wrote:
My suggestion is to change the II to III for now, until dynamic II <-> III switching
is implemented. The patch is very simple and ready to be sent to the Gerrit.
I agree that this is an ok fix for now.
If you have time - could you look at implementing all 24 specified combinations while you're at this code? And check that all existing combinations are implemented correctly. :)
Updated by fixeria about 7 years ago
- Status changed from In Progress to Closed
- Assignee changed from msuraev to fixeria
- % Done changed from 90 to 100
- Spec Reference set to http://www.qtc.jp/3GPP/Specs/GSM_GERAN/0502-8b0.pdf
Updated by fixeria about 7 years ago
If you have time - could you look at implementing all 24 specified
combinations while you're at this code? And check that all existing
combinations are implemented correctly.
I am not so good in the OsmoTRX source code, but I'll try :)
