Open Source Mobile Communications: Issueshttps://projects.osmocom.org/https://projects.osmocom.org/favicon.ico?16647414092024-02-28T08:48:26ZOpen Source Mobile Communications
Redmine libosmo-abis - Bug #6379 (Resolved): ttcn3-{msc,sgsn}-test regressions (IUT SIGSEGV)https://projects.osmocom.org/issues/63792024-02-28T08:48:26Zfixeria
<p>Both testsuites exhibit massive regressions since a few days ago:</p>
<p><a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-msc-test/2308/">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-msc-test/2308/</a> +213 failures<br /><a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-sgsn-test/2264/">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-sgsn-test/2264/</a> +70 failures</p>
<p>The artifacts generated while running those testsuites contain core dump files, so the IUT is crashing.</p>
<p>I managed to reproduce the problem by running ttcn3-msc-test against the most recent version of osmo-msc:</p>
<pre>
20240228153930783 DLGSUP NOTICE GSUP connecting to 127.0.0.1:4222 (gsup_client.c:74)
20240228153930783 DLINP NOTICE 127.0.0.1:4222 connection done (ipa.c:143)
Program received signal SIGSEGV, Segmentation fault.
0x00007ffff7c02274 in ipaccess_bts_handle_ccm (link=link@entry=0x55555584bef0, dev=0x55555584a920, msg=msg@entry=0x555555889b10) at ../../../src/libosmo-abis/src/input/ipaccess.c:897
897 LOGPIL(line, DLINP, LOGL_NOTICE, "received ID_GET for unit ID %u/%u/%u\n",
(gdb) bt
#0 0x00007ffff7c02274 in ipaccess_bts_handle_ccm (link=link@entry=0x55555584bef0, dev=0x55555584a920, msg=msg@entry=0x555555889b10) at ../../../src/libosmo-abis/src/input/ipaccess.c:897
#1 0x00007ffff7c1aa7a in gsup_client_read_cb (link=0x55555584bef0, msg=0x555555889b10) at ../../../../src/osmo-hlr/src/gsupclient/gsup_client.c:209
#2 0x00007ffff7bfd0df in ipa_client_read (link=0x55555584bef0) at ../../../src/libosmo-abis/src/input/ipa.c:77
#3 ipa_client_fd_cb (ofd=<optimized out>, what=1) at ../../../src/libosmo-abis/src/input/ipa.c:151
#4 0x00007ffff7aefc2f in poll_disp_fds (n_fd=<optimized out>) at ../../../../src/libosmocore/src/core/select.c:419
#5 _osmo_select_main (polling=polling@entry=0) at ../../../../src/libosmocore/src/core/select.c:457
#6 0x00007ffff7aefd5e in osmo_select_main_ctx (polling=polling@entry=0) at ../../../../src/libosmocore/src/core/select.c:513
#7 0x000055555556971d in main (argc=<optimized out>, argv=<optimized out>) at ../../../../src/osmo-msc/src/osmo-msc/msc_main.c:846
</pre> OsmoHNBGW - Bug #6302 (Resolved): ttcn3-hnbgw-test-latest regression (IUT segmentation fault)https://projects.osmocom.org/issues/63022023-12-12T12:31:45Zfixeria
<p>Starting from December 5th, we're seeing regressions in ttcn3-hnbgw-test <strong>latest</strong>:</p>
<p><a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-hnbgw-test-latest/535/">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-hnbgw-test-latest/535/</a> (+28 failures)</p>
<p>All affected testcases fail due to a DTE:</p>
<pre>
MTC@6005ed7d57b8: setverdict(fail): none -> fail reason: ""VTY Timeout for prompt: enable"", new component reason: ""VTY Timeout for prompt: enable""
</pre>
<p>We can also see a coredump file in the artifacts:</p>
<p><a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-hnbgw-test-latest/535/artifact/logs/hnbgw/core">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-hnbgw-test-latest/535/artifact/logs/hnbgw/core</a></p>
<p>I managed to reproduce the problem locally and examined the coredump in gdb:</p>
<pre>
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x00007f75debf1489 in on_success (data=<optimized out>, ci=0x562ca9a8f690) at ./src/libosmo-mgcp-client/mgcp_client_endpoint_fsm.c:539
539 ./src/libosmo-mgcp-client/mgcp_client_endpoint_fsm.c: No such file or directory.
(gdb) bt
#0 0x00007f75debf1489 in on_success (data=<optimized out>, ci=0x562ca9a8f690) at ./src/libosmo-mgcp-client/mgcp_client_endpoint_fsm.c:539
#1 osmo_mgcpc_ep_fsm_handle_ci_events (fi=<optimized out>, event=<optimized out>, data=<optimized out>) at ./src/libosmo-mgcp-client/mgcp_client_endpoint_fsm.c:957
#2 0x00007f75deaf2ef0 in _osmo_fsm_inst_dispatch (fi=0x562ca9a8be50, event=0, data=0x562ca9a9603c, file=0x7f75debf5ba3 "mgcp_client_fsm.c", line=446) at ./src/core/fsm.c:875
#3 0x00007f75deaf2ef0 in _osmo_fsm_inst_dispatch (fi=0x562ca9a95c10, event=3, data=0x562ca9a95d40, file=0x7f75debf5ba3 "mgcp_client_fsm.c", line=429) at ./src/core/fsm.c:875
#4 0x00007f75debe2817 in mgcp_client_handle_response (mgcp=0x562ca9a7d970, pending=0x562ca9a8b840, response=<optimized out>) at ./src/libosmo-mgcp-client/mgcp_client.c:246
#5 0x00007f75debe2dc4 in mgcp_client_rx (mgcp=mgcp@entry=0x562ca9a7d970, msg=msg@entry=0x562ca9a96380) at ./src/libosmo-mgcp-client/mgcp_client.c:741
#6 0x00007f75debe3da7 in mgcp_do_read (fd=0x562ca9a7ddb0) at ./src/libosmo-mgcp-client/mgcp_client.c:771
#7 0x00007f75deb0f241 in osmo_wqueue_bfd_cb (fd=0x562ca9a7ddb0, what=1) at ./src/core/write_queue.c:47
#8 0x00007f75deb00a94 in poll_disp_fds (n_fd=<optimized out>) at ./src/core/select.c:419
#9 _osmo_select_main (polling=polling@entry=0) at ./src/core/select.c:457
#10 0x00007f75deb00ba6 in osmo_select_main_ctx (polling=polling@entry=0) at ./src/core/select.c:513
#11 0x0000562ca98dc6e2 in main (argc=3, argv=0x7ffc2bf14318) at ./src/osmo-hnbgw/osmo_hnbgw_main.c:317
</pre>
<p>Looks like the problem is actually in libosmo-mgcp-client rather than in osmo-hnbgw?</p>
<pre>
ii libosmo-mgcp-client12:amd64 1.12.1 amd64 libosmo-mgcp-client: Osmocom's Media Gateway Control Protocol client utilities
ii libosmocore 1.9.2 amd64 Open Source MObile COMmunications CORE library (metapackage)
ii osmo-hnbgw 1.5.0 amd64 OsmoHNBGW: Osmocom Home Node B Gateway
</pre> libosmocore - Bug #6299 (Resolved): logging: segmentation fault in _output_buf()https://projects.osmocom.org/issues/62992023-12-10T07:48:08Zfixeria
<p>ttcn3-bts-test is broken for a few days. The Console Output indicates that something is wrong with the virtphy container:</p>
<p><a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test/2240/console">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test/2240/console</a></p>
<pre>
Error response from daemon: Cannot kill container: jenkins-ttcn3-bts-test-2240-virtphy: No such container: jenkins-ttcn3-bts-test-2240-virtphy
</pre>
<p>The artifacts contain a core file:</p>
<p><a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test/2240/artifact/logs/virtphy/">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test/2240/artifact/logs/virtphy/</a></p>
<p>I can reproduce the problem locally, virtphy crashes immediately after being started:</p>
<pre>
(gdb) r
Starting program: /home/fixeria/projects/osmocom/bb/src/host/virt_phy/src/virtphy
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/usr/lib/libthread_db.so.1".
Program received signal SIGSEGV, Segmentation fault.
0x00007ffff7d31468 in ?? () from /usr/lib/libc.so.6
(gdb) bt
#0 0x00007ffff7d31468 in ?? () from /usr/lib/libc.so.6
#1 0x00007ffff7d0be16 in snprintf () from /usr/lib/libc.so.6
#2 0x00007ffff7d799c7 in ?? () from /usr/lib/libc.so.6
#3 0x00007ffff7d79b2f in ctime_r () from /usr/lib/libc.so.6
#4 0x00007ffff7f67037 in _output_buf (buf=buf@entry=0x7fffffffcc90 "", buf_len=buf_len@entry=4096, target=target@entry=0x555555588140, subsys=subsys@entry=2, level=level@entry=3, file=file@entry=0x5555555643ce "virtphy.c",
line=248, cont=0, format=0x5555555643e0 "Virtual physical layer starting up...\n", ap=0x7fffffffdd00) at ../../../../src/libosmocore/src/core/logging.c:520
#5 0x00007ffff7f675de in _output (target=target@entry=0x555555588140, subsys=subsys@entry=2, level=level@entry=3, file=file@entry=0x5555555643ce "virtphy.c", line=line@entry=248, cont=cont@entry=0,
format=0x5555555643e0 "Virtual physical layer starting up...\n", ap=0x7fffffffdd00) at ../../../../src/libosmocore/src/core/logging.c:606
#6 0x00007ffff7f678ee in osmo_vlogp (subsys=<optimized out>, level=3, file=0x5555555643ce "virtphy.c", line=248, cont=0, format=0x5555555643e0 "Virtual physical layer starting up...\n", ap=0x7fffffffdd70)
at ../../../../src/libosmocore/src/core/logging.c:698
#7 0x00007ffff7f67adf in logp2 (subsys=<optimized out>, level=<optimized out>, file=<optimized out>, line=<optimized out>, cont=<optimized out>, format=<optimized out>) at ../../../../src/libosmocore/src/core/logging.c:734
#8 0x0000555555557bd8 in main (argc=1, argv=0x7fffffffdf78) at virtphy.c:248
</pre> OsmocomBB - Bug #6206 (Resolved): modem: "UL_TBF_ASS[0x5570b55bf0]{IDLE}: Event CREATE_RLCMAC_MSG...https://projects.osmocom.org/issues/62062023-10-04T21:17:45Zfixeria
<p>Somehow I am unable to attach to the network anymore, most likely due to the following error:</p>
<pre>
20231004210952228 DGMM INFO gmm_prim.c:809 Rx from lower layers: LL-UNITDATA.indication
20231004210952228 DGMM INFO gmm.c:1248 GMME(IMSI-001010000000101:PTMSI-11223344:TLLI-91223344) Rx GMM IDENTITY REQUEST mi_type=IMEI force_stdby=0
20231004210952228 DGMM INFO gmm.c:571 GMME(IMSI-001010000000101:PTMSI-11223344:TLLI-91223344) Tx GMM IDENTITY RESPONSE
20231004210952228 DLLC INFO llc_prim.c:157 Rx from upper layers: LL-UNITDATA.request
20231004210952229 DLLC DEBUG llc.c:145 modem_llc_prim_down_cb(): Rx GRR-UNITDATA.request ll=[01 c0 05 08 16 08 0a 00 00 00 00 00 21 43 ba 61 ac ]
20231004210952229 DRLCMAC INFO rlcmac_prim.c:522 Rx from upper layers: GRR-UNITDATA.request
20231004210952270 DRLCMAC INFO fsm.c:456 UL_TBF[0x5570b55ac0]{NEW}: Allocated
20231004210952270 DRLCMAC INFO fsm.c:456 UL_TBF_ASS[0x5570b55bf0]{IDLE}: Allocated
20231004210952270 DRLCMAC INFO tbf_ul_ass_fsm.c:709 UL_TBF_ASS[0x5570b55bf0]{IDLE}: Received Event START_FROM_DL_TBF
20231004210952270 DRLCMAC INFO tbf_ul_ass_fsm.c:301 UL_TBF[0x5570b55ac0]{NEW}: Received Event UL_ASS_START
20231004210952270 DRLCMAC INFO tbf_ul_fsm.c:148 UL_TBF[0x5570b55ac0]{NEW}: state_chg to ASSIGN
20231004210952270 DRLCMAC INFO tbf_ul_ass_fsm.c:303 UL_TBF_ASS[0x5570b55bf0]{IDLE}: state_chg to WAIT_PKT_UL_ASS
20231004210952370 DRLCMAC INFO rlcmac.c:793 TS=3 FN=1928173 Rx Pkt UL ASS
20231004210952370 DRLCMAC INFO tbf_ul.c:343 UL_TBF_ASS[0x5570b55bf0]{WAIT_PKT_UL_ASS}: Received Event RX_PKT_UL_ASS
20231004210952370 DRLCMAC INFO tbf_ul_ass_fsm.c:426 UL_TBF_ASS[0x5570b55bf0]{WAIT_PKT_UL_ASS}: state_chg to COMPLETED
20231004210952370 DRLCMAC INFO tbf_ul_ass_fsm.c:515 UL_TBF[0x5570b55ac0]{ASSIGN}: Received Event UL_ASS_COMPL
20231004210952370 DRLCMAC INFO tbf_ul.c:130 TBF(UL:NR-1:TLLI-91223344) Send L1CTL-CFG_UL_TBF.req ul_tbf_nr=1 ul_slotmask=0x08 tbf_starting_time(present=0 fn=0)
20231004210952371 DRLCMAC INFO tbf_ul_fsm.c:162 UL_TBF[0x5570b55ac0]{ASSIGN}: state_chg to FLOW
20231004210952371 DRLCMAC INFO tbf_ul_ass_fsm.c:517 UL_TBF_ASS[0x5570b55bf0]{COMPLETED}: state_chg to IDLE
20231004210952389 DRLCMAC INFO rlcmac.c:793 TS=3 FN=1928177 Rx Pkt DL Dummy Ctrl Block
20231004210952408 DRLCMAC INFO rlcmac.c:793 TS=3 FN=1928181 Rx Pkt DL Dummy Ctrl Block
20231004210952408 DRLCMAC INFO tbf_ul_ass_fsm.c:798 UL_TBF_ASS[0x5570b55bf0]{IDLE}: Received Event CREATE_RLCMAC_MSG
20231004210952408 DRLCMAC ERROR tbf_ul_ass_fsm.c:798 UL_TBF_ASS[0x5570b55bf0]{IDLE}: Event CREATE_RLCMAC_MSG not permitted
</pre>
<p>AFAICS, the PCU allocates us an Uplink TBF and we're trying to ACK it, but failing to do so (<code>CREATE_RLCMAC_MSG not permitted</code>).</p>
<p>osmocom-bb.git 615a88f69b52e786abab2001cb442329439711dc<br />libosmo-gprs.git 5162449b71c4285e6c032fb0df39e8c1ba86835d</p>
<p>100% (5/5 times) reproduceable on the mssdr-ms host.</p>
<p>It should be noted that I have disabled osmo-pcu's power saving mode by hacking the code (needed for debugging <a class="issue tracker-1 status-1 priority-3 priority-high3" title="Bug: osmo-trx-ms: lots of @Received bad frame (rc=-1, ber=444/444)@ (New)" href="https://projects.osmocom.org/issues/6200">#6200</a>).</p> OsmocomBB - Bug #6200 (New): osmo-trx-ms: lots of @Received bad frame (rc=-1, ber=444/444)@https://projects.osmocom.org/issues/62002023-10-03T16:46:40Zfixeria
<p>Hi <a class="user active" href="https://projects.osmocom.org/users/52">Hoernchen</a>,</p>
<p>we had a debugging session with <a class="user active" href="https://projects.osmocom.org/users/30187">pespin</a> today and we got the mssdr-ms side to work more or less reliably. But we noticed a weird problem:</p>
<pre>
20231003152951965 DL1C NOTICE trxcon(0)[0x5579a42900]{BCCH_CCCH}: L1CTL_DM_EST_REQ indicates single ARFCN GSM900 979 (l1ctl.c:572)
20231003152951965 DSCH NOTICE trxcon(0)[0x5579a42900]: Reset scheduler (sched_trx.c:190)
20231003152951965 DSCH NOTICE trxcon(0)[0x5579a42900]: Delete TDMA timeslot #0 (sched_trx.c:226)
20231003152951965 DSCH NOTICE trxcon(0)[0x5579a42900]: Add a new TDMA timeslot #4 (sched_trx.c:207)
20231003152951965 DSCH NOTICE trxcon(0)[0x5579a42900]: (Re)configure TDMA timeslot #4 as PDCH (sched_trx.c:276)
20231003152951966 DSCH NOTICE trxcon(0)[0x5579a42900]: TS4-PDTCH activating (sched_trx.c:476)
20231003152951966 DSCH NOTICE trxcon(0)[0x5579a42900]: TS4-PTCCH activating (sched_trx.c:476)
20231003152953364 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=86/456) at fn=513573 (sched_lchan_pdtch.c:94)
20231003152954366 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=87/456) at fn=513790 (sched_lchan_pdtch.c:94)
20231003152954804 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513885 (sched_lchan_pdtch.c:94)
20231003152954827 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513890 (sched_lchan_pdtch.c:94)
20231003152954846 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513894 (sched_lchan_pdtch.c:94)
20231003152954864 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513898 (sched_lchan_pdtch.c:94)
20231003152954887 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513903 (sched_lchan_pdtch.c:94)
20231003152954906 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513907 (sched_lchan_pdtch.c:94)
20231003152954924 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513911 (sched_lchan_pdtch.c:94)
20231003152954947 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513916 (sched_lchan_pdtch.c:94)
20231003152954966 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513920 (sched_lchan_pdtch.c:94)
20231003152954984 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513924 (sched_lchan_pdtch.c:94)
20231003152955007 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513929 (sched_lchan_pdtch.c:94)
20231003152955025 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513933 (sched_lchan_pdtch.c:94)
20231003152955044 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513937 (sched_lchan_pdtch.c:94)
20231003152955067 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513942 (sched_lchan_pdtch.c:94)
20231003152955085 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513946 (sched_lchan_pdtch.c:94)
20231003152955104 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513950 (sched_lchan_pdtch.c:94)
20231003152955127 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513955 (sched_lchan_pdtch.c:94)
20231003152955145 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513959 (sched_lchan_pdtch.c:94)
20231003152955164 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513963 (sched_lchan_pdtch.c:94)
20231003152955188 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513968 (sched_lchan_pdtch.c:94)
20231003152955205 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513972 (sched_lchan_pdtch.c:94)
20231003152955224 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513976 (sched_lchan_pdtch.c:94)
20231003152955248 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513981 (sched_lchan_pdtch.c:94)
20231003152955265 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513985 (sched_lchan_pdtch.c:94)
20231003152955284 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513989 (sched_lchan_pdtch.c:94)
20231003152955308 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513994 (sched_lchan_pdtch.c:94)
20231003152955325 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=513998 (sched_lchan_pdtch.c:94)
20231003152955344 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=514002 (sched_lchan_pdtch.c:94)
20231003152955368 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=514007 (sched_lchan_pdtch.c:94)
20231003152955385 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=514011 (sched_lchan_pdtch.c:94)
20231003152955404 DSCHD ERROR trxcon(0)[0x5579a42900]: TS4-PDTCH Received bad frame (rc=-1, ber=444/444) at fn=514015 (sched_lchan_pdtch.c:94)
</pre>
<p>It's not seen during the GMM ATTACH and SM PDP CTX ACT procedures, but only when we tried sending some data (ICMP ping) over the tun interface.<br />As can be seen, quite a lot of Downlink PDCH blocks not being decoded. The <code>BER=444/444</code> makes me think that received bursts were all 0 (neither -127 nor 127).<br />This is enlarging the ping delays significantly (from ~600ms to ~5000ms ==> ~10 times):</p>
<pre>
PING 176.16.222.1 (176.16.222.1) 56(84) bytes of data.
64 bytes from 176.16.222.1: icmp_seq=1 ttl=64 time=681 ms
64 bytes from 176.16.222.1: icmp_seq=2 ttl=64 time=803 ms
64 bytes from 176.16.222.1: icmp_seq=3 ttl=64 time=625 ms
64 bytes from 176.16.222.1: icmp_seq=4 ttl=64 time=525 ms
64 bytes from 176.16.222.1: icmp_seq=5 ttl=64 time=5646 ms
64 bytes from 176.16.222.1: icmp_seq=6 ttl=64 time=4678 ms
64 bytes from 176.16.222.1: icmp_seq=7 ttl=64 time=3911 ms
64 bytes from 176.16.222.1: icmp_seq=8 ttl=64 time=2948 ms
64 bytes from 176.16.222.1: icmp_seq=9 ttl=64 time=1984 ms
64 bytes from 176.16.222.1: icmp_seq=10 ttl=64 time=1020 ms
64 bytes from 176.16.222.1: icmp_seq=11 ttl=64 time=602 ms
64 bytes from 176.16.222.1: icmp_seq=12 ttl=64 time=742 ms
64 bytes from 176.16.222.1: icmp_seq=13 ttl=64 time=5741 ms
64 bytes from 176.16.222.1: icmp_seq=14 ttl=64 time=4769 ms
64 bytes from 176.16.222.1: icmp_seq=15 ttl=64 time=3824 ms
64 bytes from 176.16.222.1: icmp_seq=16 ttl=64 time=2860 ms
64 bytes from 176.16.222.1: icmp_seq=17 ttl=64 time=1896 ms
64 bytes from 176.16.222.1: icmp_seq=18 ttl=64 time=932 ms
64 bytes from 176.16.222.1: icmp_seq=19 ttl=64 time=813 ms
64 bytes from 176.16.222.1: icmp_seq=20 ttl=64 time=653 ms
64 bytes from 176.16.222.1: icmp_seq=21 ttl=64 time=5630 ms
64 bytes from 176.16.222.1: icmp_seq=22 ttl=64 time=4658 ms
64 bytes from 176.16.222.1: icmp_seq=23 ttl=64 time=3893 ms
64 bytes from 176.16.222.1: icmp_seq=24 ttl=64 time=2929 ms
64 bytes from 176.16.222.1: icmp_seq=25 ttl=64 time=1969 ms
64 bytes from 176.16.222.1: icmp_seq=26 ttl=64 time=1005 ms
64 bytes from 176.16.222.1: icmp_seq=27 ttl=64 time=546 ms
64 bytes from 176.16.222.1: icmp_seq=28 ttl=64 time=686 ms
</pre>
<p>This looks like a PHY problem to me, so assigning to you.</p> OsmoSGSN - Bug #5880 (In Progress): User Manual sections 11.1.1-2 document non-existing (removed?...https://projects.osmocom.org/issues/58802023-01-27T12:08:58Zfixeria
<p>This problem was reported by a user in the IRC:</p>
<pre>
18:55 < PJHarvy> i can't understand: in osmo sgsn manual we use:
18:55 < PJHarvy> encapsulation udp local-ip 127.0.0.1 1
18:55 < PJHarvy> encapsulation udp local-port 23000. but my version doesn't support this commands
</pre>
<p>The current <a class="external" href="https://downloads.osmocom.org/docs/latest/osmosgsn-usermanual.pdf">https://downloads.osmocom.org/docs/latest/osmosgsn-usermanual.pdf</a> indeed lists these commands, which do not exist.</p> Cellular Network Infrastructure - Bug #5635 (Resolved): ttcn3-bts-test: TC_rsl_ms_pwr_dyn_{ass_up...https://projects.osmocom.org/issues/56352022-07-27T00:24:18Zfixeria
<p>After the recent changes in osmocom-bb.git/trxcon, we started to see some new regressions. Some of them caused by the problem explained in <a class="issue tracker-2 status-3 priority-2 priority-default closed" title="Feature: Separate TDMA scheduler into a library (libtdmasched) (Resolved)" href="https://projects.osmocom.org/issues/3761">#3761</a>:</p>
<blockquote>
<ul>
<li>Sending L1 SACCH header = { 0x00, 0x00 } in cached SACCH PDUs.
<ul>
<li>You'll see "FIXME: no direct access to trx->{tx_power,ta}" during compilation.</li>
<li>Makes <code>TC_rsl_ms_pwr_dyn_{ass_updown,max}</code> and <code>TC_ms_pwr_ctrl_{constant,pf_ewma}</code> fail.</li>
</ul></li>
</ul>
</blockquote>
<p>The problem is likely in the testsuite itself, because generally we should not rely on cached measurements.</p> OsmoBTS - Bug #5518 (Rejected): osmo-bts-trx: Downlink FACCH/H scheduling is not working properlyhttps://projects.osmocom.org/issues/55182022-04-09T15:12:31Zfixeria
<p>It was reported by a customer that no voice can be heard during the emergency calls, while the normal MO/MT calls are working fine. The MS originating an emergency call indicates RxQual=7 in the RR Measurement Reports, whereas the Uplink measurements generated by the BTS indicate RxQual=0. This problem is specific to TCH/H, full rate channels are not affected.</p>
<p>The key difference from normal calls is that emergency calls are established via the <strong>early assignment</strong>: a traffic channel gets activated in signalling mode and after the call establishment it gets modified to one of the speech modes. Also, the same problem with no voice can be reproduced in a setup with no SDCCH channels - this would force the BSC to use early assignment even for the normal calls.</p>
<p>After several hours of experiments with USRP B210 and after reading the source code, I found out that scheduling of the <strong>Downlink</strong> FACCH on TCH/H is completely broken. Attached you can find a PCAP file containing A-bis/RSL traces and GSMTAP Um frames showing the problem. One can see LAPDm errors and retransmissions during the call establishment. I tried downgrading osmo-bts down to 1.2.0 (Jan 2020) without any luck.</p>
<p>A reasonable question is why didn't ttcn3-bts-test catch this? Because we use trxcon as the MS side scheduler, which was written by looking at osmo-bts-trx as the reference implementation. There can be similar bugs in there, so in this regard we're testing the implementation against itself. Most likely it needs to be fixed too.</p> OsmoBSC - Bug #5344 (Resolved): ttcn3-bsc-test: handover regressionshttps://projects.osmocom.org/issues/53442021-12-08T15:54:35Zfixeria
<p>Since recently, the following test cases constantly fail on Jenkins:</p>
<pre>
BSC_Tests.TC_srvcc_eutran_to_geran_ho_out
BSC_Tests.TC_srvcc_eutran_to_geran_ho_out_forbid_fast_return
BSC_Tests.TC_ho_out_of_this_bsc
</pre>
<p>Below are the related test reports, in which they started to fail (Nov 25):</p>
<p><a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bsc-test/1572/">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bsc-test/1572/</a><br /><a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bsc-test-latest/1151/">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bsc-test-latest/1151/</a><br /><a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3-centos/job/TTCN3-centos-bsc-test/556/">https://jenkins.osmocom.org/jenkins/view/TTCN3-centos/job/TTCN3-centos-bsc-test/556/</a></p>
<p>I believe this patch is somehow related to:</p>
<p><a class="external" href="https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/26354">https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/26354</a></p>
<p>because it was merged on Nov 24, just before the tests started to fail.</p>
<p>Interestingly enough, I cannot reproduce the failures by running test cases on my machine.</p> OsmoBTS - Bug #5251 (Resolved): VAMOS: CHANnel ACTIVation on shadow timeslots is brokenhttps://projects.osmocom.org/issues/52512021-10-08T20:05:15Zfixeria
<p>Starting from <a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test/1432/">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test/1432/</a>, we see new regressions affecting all VAMOS related test cases. The problem is that osmo-bts started to NACK CHANnel ACTIVaction messages for lchans on the shadow timeslots:</p>
<pre>
(bts=0,trx=0,ts=1,shadow,pchan=TCH/F) rx chan activ but TS not in nm_state oper=ENABLED avail=OK, nack!
</pre>
<p>because they do not reflect the OML states of primary timeslots:</p>
<pre><code class="c syntaxhl"><span class="k">if</span> <span class="p">(</span><span class="n">ts</span><span class="o">-></span><span class="n">mo</span><span class="p">.</span><span class="n">nm_state</span><span class="p">.</span><span class="n">operational</span> <span class="o">!=</span> <span class="n">NM_OPSTATE_ENABLED</span> <span class="o">||</span>
<span class="n">ts</span><span class="o">-></span><span class="n">mo</span><span class="p">.</span><span class="n">nm_state</span><span class="p">.</span><span class="n">availability</span> <span class="o">!=</span> <span class="n">NM_AVSTATE_OK</span><span class="p">)</span> <span class="p">{</span>
<span class="n">LOGP</span><span class="p">(</span><span class="n">DRSL</span><span class="p">,</span> <span class="n">LOGL_ERROR</span><span class="p">,</span> <span class="s">"%s rx chan activ but TS not in nm_state oper=ENABLED avail=OK, nack!</span><span class="se">\n</span><span class="s">"</span><span class="p">,</span>
<span class="n">gsm_ts_and_pchan_name</span><span class="p">(</span><span class="n">ts</span><span class="p">));</span>
<span class="k">return</span> <span class="n">rsl_tx_chan_act_nack</span><span class="p">(</span><span class="n">lchan</span><span class="p">,</span> <span class="n">RSL_ERR_RR_UNAVAIL</span><span class="p">);</span>
<span class="p">}</span>
<span class="n">and</span> <span class="n">all</span> <span class="n">members</span> <span class="n">of</span> <span class="n">ts</span><span class="o">-></span><span class="n">mo</span><span class="p">.</span><span class="n">nm_state</span> <span class="n">are</span> <span class="n">zero</span><span class="o">-</span><span class="n">initialized</span><span class="p">.</span>
</code></pre> OsmoBTS - Bug #5248 (Resolved): Memory leaks across A-bis/RSL connectionhttps://projects.osmocom.org/issues/52482021-10-06T08:29:15Zfixeria
<p>While working on ttcn3-bts-test, I left osmo-bts running for a while and ran out of memory. Below are the biggest talloc chunks:</p>
<pre>
OsmoBTS# show talloc-context application full tree 0x608000000380
full talloc report on 'OsmoBTS context' (total 25932818 bytes in 2379 blocks)
abis contains 197460 bytes in 1481 blocks (ref 0) 0x608000000380
unixsocket contains 1 bytes in 1 blocks (ref 0) 0x60b00014f060
ipa contains 1213 bytes in 13 blocks (ref 0) 0x60b00014efb0
struct ipa_client_conn contains 202 bytes in 2 blocks (ref 0) 0x6120000501a0
127.0.1.1 contains 10 bytes in 1 blocks (ref 0) 0x60b000190350
struct ipa_client_conn contains 202 bytes in 2 blocks (ref 0) 0x6120000405a0
127.0.2.1 contains 10 bytes in 1 blocks (ref 0) 0x60b00018b0d0
struct ipa_client_conn contains 202 bytes in 2 blocks (ref 0) 0x61200003bda0
127.0.1.1 contains 10 bytes in 1 blocks (ref 0) 0x60b00018a1b0
struct ipa_client_conn contains 202 bytes in 2 blocks (ref 0) 0x61200000e920
127.0.1.1 contains 10 bytes in 1 blocks (ref 0) 0x60b000184170
struct ipa_client_conn contains 202 bytes in 2 blocks (ref 0) 0x612000029620
127.0.1.1 contains 10 bytes in 1 blocks (ref 0) 0x60b00017d6e0
struct ipa_client_conn contains 202 bytes in 2 blocks (ref 0) 0x612000018220
127.0.1.1 contains 10 bytes in 1 blocks (ref 0) 0x60b000176620
...
OsmoBTS# show talloc-context application 2 tree 0x627000000160
talloc report on 'OsmoBTS context' (total 598284656 bytes in 48753 blocks)
struct gsm_bts contains 598181420 bytes in 48417 blocks (ref 0) 0x627000000160
struct tlv_parsed contains 4131 bytes in 16 blocks (ref 0) 0x6210016a4560
struct tlv_parsed contains 4106 bytes in 3 blocks (ref 0) 0x6210016a3160
struct tlv_parsed contains 4117 bytes in 7 blocks (ref 0) 0x6210016a1d60
struct tlv_parsed contains 4116 bytes in 4 blocks (ref 0) 0x6210016a0960
struct tlv_parsed contains 4098 bytes in 3 blocks (ref 0) 0x62100169f560
...
struct gsm_bts_trx contains 111271976 bytes in 8983 blocks (ref 0) 0x7fcd7df16860
struct gsm_bts_trx contains 111271976 bytes in 8983 blocks (ref 0) 0x7fcd7e116860
struct gsm_bts_trx contains 111271976 bytes in 8983 blocks (ref 0) 0x7fcd7e316860
struct gsm_bts_trx contains 111271976 bytes in 8983 blocks (ref 0) 0x7fcd7e816860
</pre>
<a name="How-to-reproduce"></a>
<h2 >How to reproduce?<a href="#How-to-reproduce" class="wiki-anchor">¶</a></h2>
<p>In ttcn3-bts-test environment start everything except the testsuite, so that osmo-bts can establish A-bis/OML connections, but not the A-bis/RSL.</p>
<a name="Software-versions"></a>
<h2 >Software versions<a href="#Software-versions" class="wiki-anchor">¶</a></h2>
<pre>
libosmocore ca5ce0d84966c998e353b606a7054f8bc8366cae
libosmo-abis d2d28d83a437f7478a4dfff0c6cae5305801b881
osmo-bts 93fbcdfb39674eb3b5b7768919e14fbc8c455fc4
</pre> OsmoBSC - Bug #5172 (Resolved): Uplink is broken: wrong TSC is sent in RSL CHANnel ACTIVationhttps://projects.osmocom.org/issues/51722021-06-04T12:30:17Zfixeria
<p>With the recent master (<a class="external" href="https://git.osmocom.org/osmo-bsc/commit/?id=3512e3cf1b7fd16dbb476d5abf2eb9c13dcc876e">https://git.osmocom.org/osmo-bsc/commit/?id=3512e3cf1b7fd16dbb476d5abf2eb9c13dcc876e</a>) none of my phones can perform Location Updating. Access Burst still triggers SDCCH activation, but after that I see no RSL DATA.ind at all. The Uplink measurements (performed by BTS) indicate that the MS does transmit on allocated resource.</p>
<pre>
DRSL INFO abis_rsl.c:1547 (bts=0) CHAN RQD: reason: Location updating (ra=0x05, neci=0x01, chreq_reason=0x03)
DRLL DEBUG lchan_select.c:91 looking for lchan SDCCH8: (bts=0,trx=0,ts=1,pchan=SDCCH8,state=UNUSED) ss=0 is available
DRLL DEBUG lchan_select.c:269 (bts=0) lchan_select_by_type(SDCCH)
DRSL DEBUG abis_rsl.c:517 (bts=0,trx=0,ts=1,pchan=SDCCH8,state=IN_USE) Tx RSL Channel Activate with act_type=INITIAL
DRSL DEBUG abis_rsl.c:1169 (bts=0,trx=0,ts=1,ss=0): meas_rep_count++=1 meas_rep_last_seen_nr=0
DRSL DEBUG abis_rsl.c:1169 (bts=0,trx=0,ts=1,ss=0): meas_rep_count++=2 meas_rep_last_seen_nr=1
DRSL DEBUG abis_rsl.c:1169 (bts=0,trx=0,ts=1,ss=0): meas_rep_count++=3 meas_rep_last_seen_nr=2
DRSL DEBUG abis_rsl.c:1169 (bts=0,trx=0,ts=1,ss=0): meas_rep_count++=4 meas_rep_last_seen_nr=3
DRSL DEBUG abis_rsl.c:1169 (bts=0,trx=0,ts=1,ss=0): meas_rep_count++=5 meas_rep_last_seen_nr=4
DRLL DEBUG chan_alloc.c:231 (bts=0) channel load average is 3.03%
DRLL DEBUG chan_alloc.c:245 (bts=0) T3122 wait indicator set to 10 seconds
DRSL DEBUG abis_rsl.c:1169 (bts=0,trx=0,ts=1,ss=0): meas_rep_count++=6 meas_rep_last_seen_nr=5
DCHAN ERROR lchan_fsm.c:1649 lchan(0-0-1-SDCCH8-0)[0x55c95c66b480]{WAIT_RLL_RTP_ESTABLISH}: (type=SDCCH) lchan allocation failed in state WAIT_RLL_RTP_ESTABLISH: Timeout
</pre> Cellular Network Infrastructure - Bug #5112 (Resolved): osmo-gsm-manuals: build verification is b...https://projects.osmocom.org/issues/51122021-04-10T01:57:24Zfixeria
<p>Today I submitted a set of patches for osmo-gsm-manuals:</p>
<p><a class="external" href="https://gerrit.osmocom.org/c/osmo-gsm-manuals/+/23687">https://gerrit.osmocom.org/c/osmo-gsm-manuals/+/23687</a> TRXD: generalze description of the 'RFU' ('PAD') field<br /><a class="external" href="https://gerrit.osmocom.org/c/osmo-gsm-manuals/+/23688">https://gerrit.osmocom.org/c/osmo-gsm-manuals/+/23688</a> TRXD: clarify modulation specific length of Soft-/Hard-bits<br /><a class="external" href="https://gerrit.osmocom.org/c/osmo-gsm-manuals/+/22867">https://gerrit.osmocom.org/c/osmo-gsm-manuals/+/22867</a> TRXD: add documentation for TRXDv2 protocol</p>
<p>and all of them did not pass the build verification. <a class="user active" href="https://projects.osmocom.org/users/1741">lynxis</a> also faced this problem with his:</p>
<p><a class="external" href="https://gerrit.osmocom.org/c/osmo-gsm-manuals/+/23393">https://gerrit.osmocom.org/c/osmo-gsm-manuals/+/23393</a> common/chapters: extend gb/ns2 chapters</p>
<p>The build logs contain a very cryptic failure reason:</p>
<p><a class="external" href="https://jenkins.osmocom.org/jenkins/job/gerrit-osmo-gsm-manuals/559/a1=default,a2=default,a3=default,a4=default,label=osmocom-gerrit-debian9/console">https://jenkins.osmocom.org/jenkins/job/gerrit-osmo-gsm-manuals/559/a1=default,a2=default,a3=default,a4=default,label=osmocom-gerrit-debian9/console</a></p>
<pre>
# Do print the WARNING output but return error if any was found
# (grep -v would omit the WARNING output from the log).
asciidoc: WARNING: mgcp_extension_osmux.adoc: line 2: section title out of sequence: expected level 1, got level 2
../build/Makefile.asciidoc.inc:90: recipe for target 'test-usermanual.check' failed
make[3]: Leaving directory '/build/tests'
make[3]: *** [test-usermanual.check] Error 1
../build/Makefile.asciidoc.inc:80: recipe for target 'check' failed
</pre> Cellular Network Infrastructure - Bug #4957 (Closed): ttcn3-sip-test is broken since 15 Dec 2020https://projects.osmocom.org/issues/49572021-01-19T14:35:56Zfixeria
<p>All test cases fail under both Debian and CentOS:</p>
<p><a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-sip-test/1051/">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-sip-test/1051/</a><br /><a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3-centos/job/TTCN3-centos-sip-test/238/">https://jenkins.osmocom.org/jenkins/view/TTCN3-centos/job/TTCN3-centos-sip-test/238/</a></p>
<p>Although, the 'latest' is relatively stable:</p>
<p><a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-sip-test-latest/828/">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-sip-test-latest/828/</a></p>
<p>I spent a few hours trying to investigate what's going on. Here are some intermediate results:</p>
<ul>
<li>Q: Did sofia-sip change?
<ul>
<li>A: No. All test cases on my machine also fail with v1.12.11 that I installed back in 2019.</li>
</ul>
</li>
<li>Q: Did the test suite change?
<ul>
<li>A: I could not find any changes that would affect the test suite behavior directly:
<ul>
<li><a class="external" href="https://gerrit.osmocom.org/q/Ib4399aa488afd917e3eda5e79d56ea3797ef7c78">https://gerrit.osmocom.org/q/Ib4399aa488afd917e3eda5e79d56ea3797ef7c78</a> - only expected-results.xml was changed,</li>
<li><a class="external" href="https://gerrit.osmocom.org/q/I37db9962f51baf2c63bd58ec47ec89f773d7a255">https://gerrit.osmocom.org/q/I37db9962f51baf2c63bd58ec47ec89f773d7a255</a> - changing code that is commended out.</li>
</ul>
</li>
</ul>
</li>
<li>Q: Did osmo-sip-connector's code change?
<ul>
<li>A: Yes, some new commits have been merged recently:
<ul>
<li><a class="external" href="https://gerrit.osmocom.org/q/Ia156010194c1f4334a4966d01aadfd02fa7097a8">https://gerrit.osmocom.org/q/Ia156010194c1f4334a4966d01aadfd02fa7097a8</a></li>
<li><a class="external" href="https://gerrit.osmocom.org/q/Ic926d192c238ef84fb3ad2be27e507e010b0e93f">https://gerrit.osmocom.org/q/Ic926d192c238ef84fb3ad2be27e507e010b0e93f</a></li>
<li><a class="external" href="https://gerrit.osmocom.org/q/Ia84602955b913a3bb13de7a6a92048799f2e1955">https://gerrit.osmocom.org/q/Ia84602955b913a3bb13de7a6a92048799f2e1955</a></li>
<li><a class="external" href="https://gerrit.osmocom.org/q/I870c16d7ee5e5424304f3c1c9fb78af418ae2577">https://gerrit.osmocom.org/q/I870c16d7ee5e5424304f3c1c9fb78af418ae2577</a></li>
</ul>
</li>
<li>... downgrading before them does not change anything though :/
<ul>
<li>tried I17e1adac40ac01daee0dd83da0a6aaebd78ea0dc and I3b1bebbcc9e36be43d8d055c8d28cbb38ff21b37</li>
</ul>
</li>
</ul>
</li>
<li>Q: Did libosmocore's code change?
<ul>
<li>A: Needs to be investigated.
<ul>
<li>I tried downgrading to I781ab838bd02ac1b13d384ce3f4259e26cedb61e => nothing changed.</li>
</ul></li>
</ul></li>
</ul>
<p>The test cases fail due to DTEs listed below:</p>
<ul>
<li>"MNCC_CodecPort.ttcn:19 Dynamic test case error: Initializing a variable of enumerated type @MNCC_Types.MNCC_MsgType with invalid numeric value 346140544. (No such file or directory)" </li>
<li>"Dynamic test case error: SIP Test Port: syntax error "v" -> unexpected character at character position 1." </li>
<li>"MNCC_Emulation.ttcn:348 Dynamic test case error: Write error (Broken pipe)"</li>
</ul>
<p>Sometimes it's one reason, sometimes another. Sometimes there is no DTE but "timeout of Tguard". Weird.</p> OsmoPCU - Bug #4879 (Stalled): endless pdch.cpp:809 Got CS-N RLC block: R=0, SI=0, TFI=0, CPS=0, ...https://projects.osmocom.org/issues/48792020-11-29T23:17:31Zfixeria
<p>I just upgraded all osmo-{ran,cni} components to the recent master, and now quite often run into a situation when the MS (at least Sony Ericsson K800i, TEMS) keeps sending the same Uplink block again and again. I am not sure what exactly causes it, but I can reproduce it more or less reliably by starting Opera Mini (<a class="external" href="http://people.osmocom.org/fixeria/j2me/opera_mini.jar">http://people.osmocom.org/fixeria/j2me/opera_mini.jar</a>). When started for the first time, Opera initiates the installation process, and this is where the problem usually shows up.</p>
<pre>
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACUL INFO pdch.cpp:809 Got CS-2 RLC block: R=0, SI=0, TFI=0, CPS=0, RSB=0, rc=264
DRLCMACMEAS INFO gprs_rlcmac_meas.cpp:108 MS(TLLI=0xc5849e78, IMSI=901990000000021, TA=0, 10/0, UL DL) UL RSSI: -29 dBm
</pre>
<p>Please see the attached capture file. Some highlights:</p>
<pre>
43585 RACH!
43591 IMM ASS (single block)
43731 UL Packet Resource Request
43799 DL Packet Uplink Assignment (TS=6 USF=0)
...
43910 UL DATA (BSN=0 CV=15)
...
43915 UL DATA | TCP FIN,ACK (Opera Mini closes connection to the server)
...
43918 UL DATA (BSN=3 CV=15)
43955 UL DATA (BSN=5 CV=14) <-- 14 RLC blocks left
...
44070 UL DATA (BSN=14 CV=5)
...
44146 UL DATA (BSN=19 CV=0) <-- 0 RLC blocks left
...
44149 UL DATA (BSN=19 CV=0) <-- re-transmission
44152 UL DATA (BSN=19 CV=0) <-- re-transmission
</pre>
<p>starting from frame 44149, the MS keeps transmitting the same RLC/MAC block ('35bdc794cd2b631285b2d43513'O). Interestingly enough, after each re-transmission the PCU logs "GPRS DL CTRL: PACKET_UPLINK_ACK_NACK", but <strong>does not actually send it</strong> (dummy RLC/MAC frames are not recorded). And this goes like that unless I turn off the phone. At the same time, Downlink blocks are received and accepted by the MS on the same timeslot.</p>
<p>OsmoPCU 58cd1d2f8a0474de45112e8d6e460051494eba79<br />OsmoBTS def24f0d9af2463a5ef557d35f23abd5b4d07120</p> OsmoTRX - Bug #4828 (Resolved): Building osmo-trx-lms fails due to linker errorshttps://projects.osmocom.org/issues/48282020-10-24T00:31:48Zfixeria
<p>I have no idea why this is happening:</p>
<pre>
$ autoreconf -fi
$ ./configure --with-lms --with-uhd
$ make
...
CXXLD osmo-trx-uhd
CXXLD osmo-trx-lms
/usr/bin/ld: ./device/lms/.libs/libdevice.a(LMSDevice.o): in function `LMSDevice::do_clock_src_freq(ReferenceType, double)':
/home/wmn/wmn/osmocom/osmo-trx/Transceiver52M/device/lms/LMSDevice.cpp:493: undefined reference to `get_value_string(value_string const*, unsigned int)'
/usr/bin/ld: ./device/lms/.libs/libdevice.a(LMSDevice.o): in function `LMSDevice::assign_band_desc(gsm_band)':
/home/wmn/wmn/osmocom/osmo-trx/Transceiver52M/device/lms/LMSDevice.cpp:237: undefined reference to `osmo_panic(char const*, ...)'
collect2: error: ld returned 1 exit status
</pre>
<p>while both osmo-trx-{ipc,uhd} seem to compile just fine. Here is more detailed output:</p>
<pre>
$ make V=s
/bin/sh ../libtool --tag=CXX --mode=link g++ -lpthread -I/usr/local/include/ -pthread -I/usr/local/include/ -I/usr/local/include/ -g -O2 -o osmo-trx-lms osmo_trx_lms-osmo-trx.o ./device/lms/libdevice.la libtransceiver_common.la ../Transceiver52M/arch/x86/libarch.la ../GSM/libGSM.la ../CommonLibs/libcommon.la -lfftw3f -L/usr/local/lib -Wl,-rpath,/usr/lib -ltalloc -losmocore -L/usr/local/lib -Wl,-rpath,/usr/lib -ltalloc -losmoctrl -losmogsm -losmocore -L/usr/local/lib -Wl,-rpath,/usr/lib -ltalloc -losmovty -losmocore -lLimeSuite
libtool: link: g++ -I/usr/local/include/ -pthread -I/usr/local/include/ -I/usr/local/include/ -g -O2 -o osmo-trx-lms osmo_trx_lms-osmo-trx.o -Wl,-rpath -Wl,/usr/lib -Wl,-rpath -Wl,/usr/lib -Wl,-rpath -Wl,/usr/lib ./device/lms/.libs/libdevice.a ./.libs/libtransceiver_common.a ../Transceiver52M/arch/x86/.libs/libarch.a ../GSM/.libs/libGSM.a ../CommonLibs/.libs/libcommon.a -lpthread -L/usr/local/lib -lfftw3f /usr/local/lib/libosmoctrl.so /usr/local/lib/libosmogsm.so -lgnutls /usr/local/lib/libosmovty.so /usr/local/lib/libosmocore.so -ltalloc -lsctp -ldl -lsystemd -lLimeSuite -pthread
/usr/bin/ld: ./device/lms/.libs/libdevice.a(LMSDevice.o): in function `LMSDevice::do_clock_src_freq(ReferenceType, double)':
/home/wmn/wmn/osmocom/osmo-trx/Transceiver52M/device/lms/LMSDevice.cpp:493: undefined reference to `get_value_string(value_string const*, unsigned int)'
/usr/bin/ld: ./device/lms/.libs/libdevice.a(LMSDevice.o): in function `LMSDevice::assign_band_desc(gsm_band)':
/home/wmn/wmn/osmocom/osmo-trx/Transceiver52M/device/lms/LMSDevice.cpp:237: undefined reference to `osmo_panic(char const*, ...)'
collect2: error: ld returned 1 exit status
</pre>
<p>See also: <a class="external" href="https://jenkins.osmocom.org/jenkins/job/gerrit-osmo-trx/1007/">https://jenkins.osmocom.org/jenkins/job/gerrit-osmo-trx/1007/</a>.</p> OsmoPCU - Bug #4780 (Resolved): ttcn3-pcu-test: regression: PCU_Tests.TC_ul_all_sizes fails due t...https://projects.osmocom.org/issues/47802020-10-06T08:06:05Zfixeria
<p>Starting from build 610 in 'master' and 597 in 'latest', PCU_Tests.TC_ul_all_sizes fails due to "Timeout of T_guard". Not only in Jenkins, but also on my machine.</p> Cellular Network Infrastructure - Bug #4662 (Resolved): ttcn3-bts-test: both TC_si_sched_13_2bis_...https://projects.osmocom.org/issues/46622020-07-10T17:58:38Zfixeria
<p>Both test cases are broken since build#949 [1][2]:</p>
<pre>
Dynamic test case error: While RAW-decoding type '@GSM_SystemInformation.SystemInformation':
There is not enough bits in the buffer to decode type @GSM_RestOctets.UTRAN_GPRSMeasParamsDescOpt.presence.
</pre>
<p>I think this regression is caused by [3]. The problem is that in ttcn3-bts-test, SI2quater contains a list of UTRAN neighbor cells, that is currently not implemented in <em>SI2quaterRestOctets</em>. The coding of this list is quite complex (more complex than the E-ARFCN list), and would probably require us to implement some parts in C++. As a quick work around, we could avoid calling <em>dec_SystemInformation()</em> on SI2quater in f_l1_sample_si().</p>
<p>[1] <a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test/949/">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test/949/</a><br />[2] <a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test/949/artifact/logs/bts-tester/BTS_Tests.TC_si_sched_13_2bis_2ter_2quater.merged">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test/949/artifact/logs/bts-tester/BTS_Tests.TC_si_sched_13_2bis_2ter_2quater.merged</a><br />[3] <a class="external" href="https://gerrit.osmocom.org/q/I879c37eb51ece55d79346c6bf1a4951c3f11c77e">https://gerrit.osmocom.org/q/I879c37eb51ece55d79346c6bf1a4951c3f11c77e</a></p> OsmocomBB - Bug #4658 (Stalled): Wrong burst order in a multi-trx setuphttps://projects.osmocom.org/issues/46582020-07-08T11:45:30Zfixeria
<p>While running the existing test cases from ttcn3-bts-test on hopping channels (see <a class="issue tracker-2 status-3 priority-2 priority-default closed" title="Feature: baseband frequency hopping support for osmo-bts-trx (Resolved)" href="https://projects.osmocom.org/issues/4546">#4546</a>), I noticed that sometimes trxcon starts to consume a lot of CPU power. As it turned out, this happens because the burst loss detection logic in trxcon somehow detects that the whole TDMA hyper-frame is lost, so it tries to substitute ~2715647 allegedly lost TDMA frames with a dummy burst. Of course it's a bug, because we're not supposed to compensate more than one TDMA multi-frame period. So the problem was a missing 'return' statement:</p>
<p><a class="external" href="https://gerrit.osmocom.org/c/osmocom-bb/+/19183">https://gerrit.osmocom.org/c/osmocom-bb/+/19183</a> trxcon/scheduler: subst_frame_loss(): print current TDMA fn<br /><a class="external" href="https://gerrit.osmocom.org/c/osmocom-bb/+/19184">https://gerrit.osmocom.org/c/osmocom-bb/+/19184</a> trxcon/scheduler: fix subst_frame_loss(): do not compensate too much</p>
<p>However, I was interested to know what exactly tricks the burst detection logic to think that so many frames are lost.</p>
<pre><code class="c syntaxhl"><span class="cm">/*! Return the difference of two specified TDMA frame numbers (subtraction) */</span>
<span class="cp">#define GSM_TDMA_FN_SUB(a, b) \
((a + GSM_TDMA_HYPERFRAME - b) % GSM_TDMA_HYPERFRAME)
</span>
<span class="cm">/* How many frames elapsed since the last one? */</span>
<span class="n">elapsed</span> <span class="o">=</span> <span class="n">GSM_TDMA_FN_SUB</span><span class="p">(</span><span class="n">fn</span><span class="p">,</span> <span class="n">lchan</span><span class="o">-></span><span class="n">tdma</span><span class="p">.</span><span class="n">last_proc</span><span class="p">);</span>
<span class="k">if</span> <span class="p">(</span><span class="n">elapsed</span> <span class="o">></span> <span class="n">mf</span><span class="o">-></span><span class="n">period</span><span class="p">)</span> <span class="p">{</span>
<span class="n">LOGP</span><span class="p">(</span><span class="n">DSCHD</span><span class="p">,</span> <span class="n">LOGL_NOTICE</span><span class="p">,</span> <span class="s">"Too many (>%u) contiguous TDMA frames elapsed (%u) "</span>
<span class="s">"since the last processed fn=%u (current %u)</span><span class="se">\n</span><span class="s">"</span><span class="p">,</span>
<span class="n">mf</span><span class="o">-></span><span class="n">period</span><span class="p">,</span> <span class="n">elapsed</span><span class="p">,</span> <span class="n">lchan</span><span class="o">-></span><span class="n">tdma</span><span class="p">.</span><span class="n">last_proc</span><span class="p">,</span> <span class="n">fn</span><span class="p">);</span>
<span class="k">return</span> <span class="o">-</span><span class="n">EIO</span><span class="p">;</span>
<span class="p">}</span> <span class="k">else</span> <span class="nf">if</span> <span class="p">(</span><span class="n">elapsed</span> <span class="o">==</span> <span class="mi">0</span><span class="p">)</span> <span class="p">{</span>
<span class="n">LOGP</span><span class="p">(</span><span class="n">DSCHD</span><span class="p">,</span> <span class="n">LOGL_ERROR</span><span class="p">,</span> <span class="s">"No TDMA frames elapsed since the last processed "</span>
<span class="s">"fn=%u, must be a bug?</span><span class="se">\n</span><span class="s">"</span><span class="p">,</span> <span class="n">lchan</span><span class="o">-></span><span class="n">tdma</span><span class="p">.</span><span class="n">last_proc</span><span class="p">);</span>
<span class="k">return</span> <span class="o">-</span><span class="n">EIO</span><span class="p">;</span>
<span class="p">}</span>
</code></pre>
<p>And slightly more informative logging message gives us a hint:</p>
<pre>
sched_trx.c:640 Too many (>104) contiguous TDMA frames elapsed (2715647) since the last processed fn=633 (current fn=632)
</pre>
<p>so, a burst with TDMA fn=632 is for some reason received <strong>late</strong>, since we already received a burst with TDMA fn=633.</p>
<p>This is definitely unexpected, and of course subtraction would result in a huge number: ((632 + 2715648) - 633) % 2715648 == 2715647.</p> OsmoBSC - Bug #4624 (Resolved): osmo-bsc leaks memoryhttps://projects.osmocom.org/issues/46242020-06-19T19:23:32Zfixeria
<p>While investigating <a class="issue tracker-1 status-3 priority-3 priority-high3 closed" title="Bug: ttcn3-bsc-test: all LCLS test cases broken since build #987 (Resolved)" href="https://projects.osmocom.org/issues/4619">#4619</a>, I noticed that osmo-bsc (or libosmo-abis?) leaks memory.</p>
<p>Before running LCLS test cases:</p>
<pre>
OsmoBSC# show talloc-context application brief
talloc report on 'osmo-bsc' (total 914581 bytes in 584 blocks)
telnet_connection contains 89 bytes in 2 blocks (ref 0) 0x561a66e7a910
0.0.0.0 contains 8 bytes in 1 blocks (ref 0) 0x561a66e9a420
struct osmo_ss7_instance contains 3452 bytes in 28 blocks (ref 0) 0x561a66e7b6a0
struct cmd_element contains 122 bytes in 2 blocks (ref 0) 0x561a66e3c3a0
struct cmd_element contains 123 bytes in 2 blocks (ref 0) 0x561a66e3b410
struct cmd_element contains 121 bytes in 2 blocks (ref 0) 0x561a66e38860
../../../../src/libosmocore/src/vty/utils.c:353 contains 168 bytes in 1 blocks (ref 0) 0x561a66c6fd10
../../../../src/libosmocore/src/vty/utils.c:353 contains 56 bytes in 1 blocks (ref 0) 0x561a66c6fc70
../../../../src/libosmocore/src/vty/utils.c:353 contains 495 bytes in 1 blocks (ref 0) 0x561a66c6fa10
../../../../src/libosmocore/src/vty/utils.c:353 contains 130 bytes in 1 blocks (ref 0) 0x561a66c5a120
abis contains 193781 bytes in 24 blocks (ref 0) 0x561a66c54630 // <--- check
struct gsm_network contains 709584 bytes in 488 blocks (ref 0) 0x561a66c53080
logging contains 5971 bytes in 11 blocks (ref 0) 0x561a66c52880
counter contains 0 bytes in 1 blocks (ref 0) 0x561a66c52810
subch_txq_entry contains 0 bytes in 1 blocks (ref 0) 0x561a66c527a0
bs11_file_list_entry contains 0 bytes in 1 blocks (ref 0) 0x561a66c52730
paging_request contains 0 bytes in 1 blocks (ref 0) 0x561a66c526c0
xua_msg contains 0 bytes in 1 blocks (ref 0) 0x561a66c52650
osmo_signal contains 480 bytes in 13 blocks (ref 0) 0x561a66c525e0
msgb contains 0 bytes in 1 blocks (ref 0) 0x561a66c52570
</pre>
<p>After running LCLS test cases:</p>
<pre>
OsmoBSC# show talloc-context application brief
talloc report on 'osmo-bsc' (total 1659989 bytes in 723 blocks)
telnet_connection contains 89 bytes in 2 blocks (ref 0) 0x560e7f96c910
0.0.0.0 contains 8 bytes in 1 blocks (ref 0) 0x560e7f98dcc0
struct osmo_ss7_instance contains 5326 bytes in 36 blocks (ref 0) 0x560e7f97af50
struct cmd_element contains 122 bytes in 2 blocks (ref 0) 0x560e7f92e3a0
struct cmd_element contains 123 bytes in 2 blocks (ref 0) 0x560e7f92d410
struct cmd_element contains 121 bytes in 2 blocks (ref 0) 0x560e7f92a860
../../../../src/libosmocore/src/vty/utils.c:353 contains 168 bytes in 1 blocks (ref 0) 0x560e7f761d10
../../../../src/libosmocore/src/vty/utils.c:353 contains 56 bytes in 1 blocks (ref 0) 0x560e7f761c70
../../../../src/libosmocore/src/vty/utils.c:353 contains 495 bytes in 1 blocks (ref 0) 0x560e7f761a10
../../../../src/libosmocore/src/vty/utils.c:353 contains 130 bytes in 1 blocks (ref 0) 0x560e7f74c120
abis contains 869141 bytes in 66 blocks (ref 0) 0x560e7f746630 // <--- check
struct gsm_network contains 777226 bytes in 570 blocks (ref 0) 0x560e7f745080
logging contains 6503 bytes in 18 blocks (ref 0) 0x560e7f744880
counter contains 0 bytes in 1 blocks (ref 0) 0x560e7f744810
subch_txq_entry contains 0 bytes in 1 blocks (ref 0) 0x560e7f7447a0
bs11_file_list_entry contains 0 bytes in 1 blocks (ref 0) 0x560e7f744730
paging_request contains 0 bytes in 1 blocks (ref 0) 0x560e7f7446c0
xua_msg contains 0 bytes in 1 blocks (ref 0) 0x560e7f744650
osmo_signal contains 480 bytes in 13 blocks (ref 0) 0x560e7f7445e0
msgb contains 0 bytes in 1 blocks (ref 0) 0x560e7f744570
</pre>
<p>Here is a full report on the 'abis' chink:</p>
<pre>
OsmoBSC# show talloc-context application full tree 0x560e7f746630
full talloc report on 'osmo-bsc' (total 1659989 bytes in 723 blocks)
abis contains 869141 bytes in 66 blocks (ref 0) 0x560e7f746630
unixsocket contains 1 bytes in 1 blocks (ref 0) 0x560e7f746880
ipa contains 820273 bytes in 56 blocks (ref 0) 0x560e7f746810
struct e1inp_line contains 48240 bytes in 3 blocks (ref 0) 0x560e7fa80dc0
reference to: struct ipaccess_line
reference to: ../../../src/libosmocore/src/rate_ctr.c:234
struct e1inp_line contains 48240 bytes in 3 blocks (ref 0) 0x560e7fa73d20
reference to: struct ipaccess_line
reference to: ../../../src/libosmocore/src/rate_ctr.c:234
struct e1inp_line contains 48240 bytes in 3 blocks (ref 0) 0x560e7fa68040
reference to: struct ipaccess_line
reference to: ../../../src/libosmocore/src/rate_ctr.c:234
struct e1inp_line contains 48240 bytes in 3 blocks (ref 0) 0x560e7fa5c360
reference to: struct ipaccess_line
reference to: ../../../src/libosmocore/src/rate_ctr.c:234
struct e1inp_line contains 48240 bytes in 3 blocks (ref 0) 0x560e7fa50680
reference to: struct ipaccess_line
reference to: ../../../src/libosmocore/src/rate_ctr.c:234
struct e1inp_line contains 48240 bytes in 3 blocks (ref 0) 0x560e7fa449a0
reference to: struct ipaccess_line
reference to: ../../../src/libosmocore/src/rate_ctr.c:234
struct e1inp_line contains 48240 bytes in 3 blocks (ref 0) 0x560e7fa38cc0
reference to: struct ipaccess_line
reference to: ../../../src/libosmocore/src/rate_ctr.c:234
struct e1inp_line contains 48240 bytes in 3 blocks (ref 0) 0x560e7fa2bc20
reference to: struct ipaccess_line
reference to: ../../../src/libosmocore/src/rate_ctr.c:234
struct e1inp_line contains 48240 bytes in 3 blocks (ref 0) 0x560e7fa1ff40
reference to: struct ipaccess_line
reference to: ../../../src/libosmocore/src/rate_ctr.c:234
struct e1inp_line contains 48240 bytes in 3 blocks (ref 0) 0x560e7fa14260
reference to: struct ipaccess_line
reference to: ../../../src/libosmocore/src/rate_ctr.c:234
struct e1inp_line contains 48240 bytes in 3 blocks (ref 0) 0x560e7fa08580
reference to: struct ipaccess_line
reference to: ../../../src/libosmocore/src/rate_ctr.c:234
struct e1inp_line contains 48240 bytes in 3 blocks (ref 0) 0x560e7f9f6500
reference to: struct ipaccess_line
reference to: ../../../src/libosmocore/src/rate_ctr.c:234
struct e1inp_line contains 48240 bytes in 3 blocks (ref 0) 0x560e7f9ea820
reference to: struct ipaccess_line
reference to: ../../../src/libosmocore/src/rate_ctr.c:234
struct e1inp_line contains 48240 bytes in 3 blocks (ref 0) 0x560e7f9deb40
reference to: struct ipaccess_line
reference to: ../../../src/libosmocore/src/rate_ctr.c:234
struct e1inp_line contains 48240 bytes in 3 blocks (ref 0) 0x560e7f9c9550
reference to: struct ipaccess_line
reference to: ../../../src/libosmocore/src/rate_ctr.c:234
struct e1inp_line contains 48240 bytes in 3 blocks (ref 0) 0x560e7f9b26b0
reference to: struct ipaccess_line
reference to: ../../../src/libosmocore/src/rate_ctr.c:234
struct e1inp_line contains 48240 bytes in 3 blocks (ref 0) 0x560e7f9a3380
reference to: struct ipaccess_line
reference to: ../../../src/libosmocore/src/rate_ctr.c:234
struct ipa_server_link contains 96 bytes in 2 blocks (ref 0) 0x560e7f97bb30
0.0.0.0 contains 8 bytes in 1 blocks (ref 0) 0x560e7f99fb90
struct ipa_server_link contains 96 bytes in 2 blocks (ref 0) 0x560e7f97ba70
0.0.0.0 contains 8 bytes in 1 blocks (ref 0) 0x560e7f985340
e1inp contains 48867 bytes in 8 blocks (ref 0) 0x560e7f7466a0
struct e1inp_line contains 48673 bytes in 3 blocks (ref 0) 0x560e7f96f050
struct ipaccess_line contains 1 bytes in 1 blocks (ref 17) 0x560e7f96d020
../../../src/libosmocore/src/rate_ctr.c:234 contains 432 bytes in 1 blocks (ref 17) 0x560e7f97ad30
e1inp_sign_link contains 193 bytes in 4 blocks (ref 0) 0x560e7f746710
struct e1inp_sign_link contains 64 bytes in 1 blocks (ref 0) 0x560e7f9c8520
struct e1inp_sign_link contains 64 bytes in 1 blocks (ref 0) 0x560e7f97b6a0
struct e1inp_sign_link contains 64 bytes in 1 blocks (ref 0) 0x560e7f97b7d0
</pre>
<p>Assigning to <a class="user active" href="https://projects.osmocom.org/users/30187">pespin</a> (as discussed) since he was been working on reference counting recently.<br />Please see a capture file (containing GSMTAP logs, all debug) attached.</p> Cellular Network Infrastructure - Bug #4619 (Resolved): ttcn3-bsc-test: all LCLS test cases broke...https://projects.osmocom.org/issues/46192020-06-17T09:14:40Zfixeria
<p>Check out <a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bsc-test/test_results_analyzer/">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bsc-test/test_results_analyzer/</a>.</p>
<p>This is probably related to my recent IPA/RSL emulation refactoring changes:</p>
<blockquote>
<p>Changes<br />1. centos-repo-install-test: new image (detail)<br />2. debian-repo-install-test: move scripts to osmo-ci (detail)<br />3. ttcn3-bts-test: enable 3 additional transceivers for BTS#0 (detail)</p>
</blockquote>
<p>Here is an extract from the build artifacts of build#987:</p>
<pre>
06:26:01.572279 921 RSL_Emulation.ttcn:556 Matching on port IPA_PT succeeded: matched
06:26:01.572304 921 RSL_Emulation.ttcn:556 Receive operation on port IPA_PT succeeded, message from IPA0-RSL-IPA(920): @IPA_Emulation.ASP_RSL_Unitdata : { conn_id := 1,
streamId := IPAC_PROTO_RSL_TRX0 (0), rsl := { msg_disc := { msg_group := RSL_MDISC_IPACCESS (63), transparent := false }, msg_type := RSL_MT_IPAC_CRCX (112), ies := { {
iei := RSL_IE_CHAN_NR (1), body := { chan_nr := { u := { ch0 := RSL_CHAN_NR_Bm_ACCH (1) }, tn := 2 } } }, { iei := RSL_IE_IPAC_SPEECH_MODE (244), body := { ipa_speech_mo
de := { reserved := '00'B, mode := RSL_IPA_SPM_RECVONLY (1), codec := RSL_IPA_CODEC_FR (0) } } }, { iei := RSL_IE_IPAC_RTP_PAYLOAD (242), body := { ipa_rtp_pt := 3 } } }
} } id 27
06:26:01.572325 921 RSL_Emulation.ttcn:556 Message with id 27 was extracted from the queue of IPA_PT.
06:26:01.572351 921 RSL_Emulation.ttcn:199 No Dchan handler for 0{ u := { ch0 := RSL_CHAN_NR_Bm_ACCH (1) }, tn := 2 }
06:26:01.572469 923 MSC_ConnectionHandler.ttcn:784 dec_PDU_ML3_NW_MS(): Decoded @MobileL3_Types.PDU_ML3_NW_MS: { discriminator := '0110'B, tiOrSkip := { skipIndicator :=
'0000'B }, msgs := { rrm := { assignmentCommand := { messageType := '00101110'B, descrOf1stChAfterTime := { timeslotNumber := '010'B, channelTypeandTDMAOffset := '00001
'B, octet3 := '43'O ("C"), octet4 := '67'O ("g") }, PowerCommand := { powerlevel := '00111'B, fPC_EP := '0'B, ePC_Mode := '0'B, spare_1 := '0'B }, frequencyList_at := om
it, cellChannelDescr := omit, descrMultislotAllocation := omit, modeOf1stChannel := { elementIdentifier := '63'O ("c"), mode := '01'O }, channelSet2 := omit, channelSet3
:= omit, channelSet4 := omit, channelSet5 := omit, channelSet6 := omit, channelSet7 := omit, channelSet8 := omit, descrOf2ndChAfterTime := omit, modeOf2ndChannel := omi
t, mobileAllocation_at := omit, startingTime := omit, frequencyList_bt := omit, descrOf1stCh_bt := omit, descrOf2ndCh_bt := omit, frequencyChannelSequence := omit, mobil
eAllocation_bt := omit, cipherModeSetting := omit, vGCS_TargetModeIndication := omit, multiRateConfiguration := omit, vGCS_Ciphering_Parameters := omit, extendedTSCSet_a
fterTime := omit, extendedTSCSet_beforeTime := omit } } } }
06:26:01.572471 921 RSL_Emulation.ttcn:563 setverdict(fail): none -> fail reason: "RSL for unknown Dchan", new component reason: "RSL for unknown Dchan"
06:26:01.572505 921 RSL_Emulation.ttcn:564 Stopping MTC. The current test case will be terminated.
06:26:01.572526 921 RSL_Emulation.ttcn:564 Stopping test component execution.
</pre>
<p>Note that ttcn3-bsc-test-latest is not affected.</p> OsmoBTS - Bug #4501 (Resolved): osmo-bts-{sysmo,oc2g,litecell15}: Packet Control Ack (in form of ...https://projects.osmocom.org/issues/45012020-04-18T11:13:42Zfixeria
<p>As was reported by <a class="user active" href="https://projects.osmocom.org/users/4282">keith</a> (originally in <a class="issue tracker-2 status-7 priority-2 priority-default" title="Feature: Acquire/update timing advance (TA) (Stalled)" href="https://projects.osmocom.org/issues/1526">#1526</a>), with 'gprs control-ack-type-rach' enabled in the BSC, osmo-pcu logs:</p>
<pre>
DL1IF <0001> ../../git/src/osmo-bts-sysmo/sysmo_l1_if.c:251 Rx PH-RA.ind for unknown L1 SAPI PRACH
</pre>
<p>this is a regression introduced in I482d60a46b9d253dfe0b16140eac9fea6420b30c:</p>
<pre>
Parent: 17954da5 (pcuif_proto.h: extend RACH.ind with TRX / TS numbers)
Author: Vadim Yanitskiy <axilirator@gmail.com>
AuthorDate: 2019-10-05 23:45:31 +0700
Commit: Vadim Yanitskiy <axilirator@gmail.com>
CommitDate: 2019-11-23 17:42:45 +0700
PTCCH: properly handle RACH.ind for PCU_IF_SAPI_PTCCH
Change-Id: I482d60a46b9d253dfe0b16140eac9fea6420b30c
Related: OS#1545
</pre>
<p>I would expect <strong>Packet Control Ack</strong> on <em>GsmL1_Sapi_Pdtch</em> or rather on <em>GsmL1_Sapi_Pacch</em>, but apparently (for some magic reason) it arrives on <em>GsmL1_Sapi_Prach</em>.</p>
<p>According to 3GPP TS 45.002, section 3.3.3.2.1:</p>
<ul>
<li>PRACH stands for Packet Random Access CHannel,</li>
<li>used to request assignment of one or several PDTCHs,</li>
<li>belongs to Packet Common Control Channel (PCCCH)!</li>
</ul>
<p>Therefore the Packet Control Ack has nothing to do with PRACH. Neither we support PCCCH (it has been deprecated by the specifications).</p>
<pre><code class="c syntaxhl"><span class="n">GsmL1_LogChComb_XIII</span> <span class="c1">///< PDTCH/F + PACCH/F + PTCCH/F</span>
</code></pre>
<p>This odd behaviour seems to be caused by the following code (see <a class="issue tracker-1 status-7 priority-2 priority-default" title="Bug: osmo-bts-{sysmo,oc2g,litecell15}: PTCCH/U is not enabled on PDCH timeslots (Stalled)" href="https://projects.osmocom.org/issues/4500">#4500</a>):</p>
<pre><code class="c syntaxhl"><span class="k">static</span> <span class="k">const</span> <span class="k">struct</span> <span class="n">sapi_dir</span> <span class="n">pdtch_sapis</span><span class="p">[]</span> <span class="o">=</span> <span class="p">{</span>
<span class="p">{</span> <span class="n">GsmL1_Sapi_Pdtch</span><span class="p">,</span> <span class="n">GsmL1_Dir_TxDownlink</span> <span class="p">},</span>
<span class="p">{</span> <span class="n">GsmL1_Sapi_Pdtch</span><span class="p">,</span> <span class="n">GsmL1_Dir_RxUplink</span> <span class="p">},</span>
<span class="p">{</span> <span class="n">GsmL1_Sapi_Ptcch</span><span class="p">,</span> <span class="n">GsmL1_Dir_TxDownlink</span> <span class="p">},</span>
<span class="p">{</span> <span class="n">GsmL1_Sapi_Prach</span><span class="p">,</span> <span class="n">GsmL1_Dir_RxUplink</span> <span class="p">},</span> <span class="c1">// <-- ?!?</span>
<span class="c">#if 0
{ GsmL1_Sapi_Ptcch, GsmL1_Dir_RxUplink },
{ GsmL1_Sapi_Pacch, GsmL1_Dir_TxDownlink }, // <-- ?!?
#endif
</span><span class="p">};</span>
</code></pre>
<p>where we enable <em>GsmL1_Sapi_Prach</em> on <em>GsmL1_LogChComb_XIII</em> (again, there is no PRACH in XIII). I guess we should enable <em>GsmL1_Sapi_Pacch</em> on direction <em>GsmL1_Dir_RxUplink</em> instead.</p>
<p>For now I submitted a blind fix: <a class="external" href="https://gerrit.osmocom.org/c/osmo-pcu/+/17669">https://gerrit.osmocom.org/c/osmo-pcu/+/17669</a>. Let's keep it WIP for now.</p> pySim - Bug #4419 (Resolved): CardConnectionException: Failed to transmit with protocol T0. Trans...https://projects.osmocom.org/issues/44192020-02-26T17:33:53Zfixeria
<p>For some reason, pySim-prog.py fails to program a SIM card when using Python 3.</p>
<pre>
Using PC/SC reader (dev=0) interface
Ready for Programming: Insert card now (or CTRL-C to cancel)
Autodetected card type: sysmoUSIM-SJS1
Generated card parameters :
> Name : Osmocom
> SMSP : e1ffffffffffffffffffffffff068100095155f5ffffffffff000000
> ICCID : [REMOVED]
> MCC/MNC : 901/70
> IMSI : 901700000025647
> Ki : [REMOVED]
> OPC : [REMOVED]
> ACC : None
> ADM1(hex): [REMOVED]
Programming ...
Card programming failed with an execption:
---------------------8<---------------------
Traceback (most recent call last):
File "./pySim-prog.py", line 751, in <module>
rc = process_card(opts, first, card_handler)
File "./pySim-prog.py", line 689, in process_card
card.program(cp)
File "/home/fixeria/osmocom/pysim/pySim/cards.py", line 602, in program
data, sw = self._scc.update_binary('2fe2', enc_iccid(p['iccid']))
File "/home/fixeria/osmocom/pysim/pySim/commands.py", line 128, in update_binary
self.select_file(ef)
File "/home/fixeria/osmocom/pysim/pySim/commands.py", line 106, in select_file
data, sw = self._tp.send_apdu_checksw(self.cla_byte + "a4" + self.sel_ctrl + "02" + i)
File "/home/fixeria/osmocom/pysim/pySim/transport/__init__.py", line 93, in send_apdu_checksw
rv = self.send_apdu(pdu)
File "/home/fixeria/osmocom/pysim/pySim/transport/__init__.py", line 68, in send_apdu
data, sw = self.send_apdu_raw(pdu)
File "/home/fixeria/osmocom/pysim/pySim/transport/pcsc.py", line 76, in send_apdu_raw
data, sw1, sw2 = self._con.transmit(apdu, CardConnection.T0_protocol)
File "/usr/lib/python3.8/site-packages/smartcard/CardConnectionDecorator.py", line 82, in transmit
return self.component.transmit(bytes, protocol)
File "/usr/lib/python3.8/site-packages/smartcard/CardConnection.py", line 146, in transmit
data, sw1, sw2 = self.doTransmit(bytes, protocol)
File "/usr/lib/python3.8/site-packages/smartcard/pcsc/PCSCCardConnection.py", line 200, in doTransmit
raise CardConnectionException(
smartcard.Exceptions.CardConnectionException: Failed to transmit with protocol T0. Transaction failed.
---------------------8<---------------------
</pre>
<p>At the same time, reading a SIM card works just fine. Switching back to Python 2 makes pySim-prog.py work again.</p>
<p>I grabbed debug output of pcscd using the following command:</p>
<pre>
$ sudo LIBCCID_ifdLogLevel=0x0007 pcscd -fd | tee /tmp/pcscd.log
</pre>
<p>Please seee attached files and the difference between them.</p> OsmoMSC - Bug #4340 (Resolved): Malformed MM Identity Response crashes OsmoMSChttps://projects.osmocom.org/issues/43402019-12-27T22:19:57Zfixeria
<p>From time to time we receive a MM Identity Response that crashes OsmoMSC:</p>
<pre>
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x00007f8ec198c5fe in __GI_abort () at abort.c:100
#2 0x00007f8ec2016210 in osmo_panic_default (args=0x7ffe75e09f88, fmt=0x558dc6301189 "Assert failed %s %s:%d\n") at ../../../src/libosmocore/src/panic.c:49
#3 osmo_panic (fmt=fmt@entry=0x558dc6301189 "Assert failed %s %s:%d\n") at ../../../src/libosmocore/src/panic.c:84
#4 0x0000558dc62f9181 in vlr_subscr_rx_id_resp (vsub=vsub@entry=0x558dc81738e0, mi=mi@entry=0x558dc811f196 "\377\377\377\377\377\377\377\377", mi_len=mi_len@entry=8)
at ../../../../src/osmo-msc/src/libvlr/vlr.c:1189
#5 0x0000558dc62ea90e in mm_rx_id_resp (msg=<optimized out>, msc_a=<optimized out>) at ../../../../src/osmo-msc/src/libmsc/gsm_04_08.c:197
#6 gsm0408_rcv_mm (msc_a=<optimized out>, msg=<optimized out>) at ../../../../src/osmo-msc/src/libmsc/gsm_04_08.c:1086
#7 0x0000558dc62c31cc in msc_a_ran_dec_from_msc_i (msc_a=msc_a@entry=0x558dc8130060, d=d@entry=0x7ffe75e0ace0) at ../../../../src/osmo-msc/src/libmsc/msc_a.c:1484
#8 0x0000558dc62c3cde in msc_a_ran_decode_cb (msc_a_fi=<optimized out>, data=0x7ffe75e0ace0, msg=0x7ffe75e0a750) at ../../../../src/osmo-msc/src/libmsc/msc_a.c:1643
#9 0x0000558dc62d0dde in ran_a_decode_l3 (ran_dec=<optimized out>, l3=<optimized out>) at ../../../../src/osmo-msc/src/libmsc/ran_msg_a.c:884
#10 0x0000558dc62c09d6 in msc_role_ran_decode (fi=0x558dc8127cb0, an_apdu=an_apdu@entry=0x7ffe75e0b370, decode_cb=decode_cb@entry=0x558dc62c3be0 <msc_a_ran_decode_cb>,
decode_cb_data=decode_cb_data@entry=0x7ffe75e0ace0) at ../../../../src/osmo-msc/src/libmsc/msub.c:589
#11 0x0000558dc62c179a in msc_a_ran_dec (msc_a=0x558dc8130060, an_apdu=0x7ffe75e0b370, from_role=<optimized out>) at ../../../../src/osmo-msc/src/libmsc/msc_a.c:184
#12 0x00007f8ec200eaf9 in _osmo_fsm_inst_dispatch (fi=0x558dc8127cb0, event=9, data=0x7ffe75e0b370, file=0x558dc630de00 "../../../../src/osmo-msc/src/libmsc/msc_i.c",
line=85) at ../../../src/libosmocore/src/fsm.c:877
#13 0x0000558dc62d0dde in ran_a_decode_l3 (ran_dec=<optimized out>, l3=<optimized out>) at ../../../../src/osmo-msc/src/libmsc/ran_msg_a.c:884
#14 0x0000558dc62c09d6 in msc_role_ran_decode (fi=0x558dc81268a0, an_apdu=0x7ffe75e0b370, decode_cb=<optimized out>, decode_cb_data=<optimized out>)
at ../../../../src/osmo-msc/src/libmsc/msub.c:589
--Type <RET> for more, q to quit, c to continue without paging--
#15 0x00007f8ec200eaf9 in _osmo_fsm_inst_dispatch (fi=0x558dc81268a0, event=event@entry=9, data=data@entry=0x7ffe75e0b370,
file=file@entry=0x558dc63129b8 "../../../../src/osmo-msc/src/libmsc/ran_peer.c", line=line@entry=412) at ../../../src/libosmocore/src/fsm.c:877
#16 0x0000558dc62d5bcd in ran_peer_st_ready (fi=<optimized out>, event=2, data=0x7ffe75e0b430) at ../../../../src/osmo-msc/src/libmsc/ran_peer.c:412
#17 0x00007f8ec200eaf9 in _osmo_fsm_inst_dispatch (fi=0x558dc8118ad0, event=2, data=data@entry=0x7ffe75e0b430,
file=file@entry=0x558dc63129b8 "../../../../src/osmo-msc/src/libmsc/ran_peer.c", line=line@entry=596) at ../../../src/libosmocore/src/fsm.c:877
#18 0x0000558dc62d69b5 in ran_peer_up_l2 (sri=0x558dc8114750, calling_addr=0x0, co=<optimized out>, conn_id=<optimized out>, l2=<optimized out>)
at ../../../../src/osmo-msc/src/libmsc/ran_peer.c:596
#19 0x0000558dc62ad606 in sccp_ran_sap_up (oph=0x558dc811f088, _scu=<optimized out>) at ../../../../src/osmo-msc/src/libmsc/sccp_ran.c:110
#20 0x00007f8ec200eaf9 in _osmo_fsm_inst_dispatch (fi=0x558dc817e4f0, event=11, data=data@entry=0x558dc8122a90,
file=file@entry=0x7f8ec1da6e08 "../../../src/libosmo-sccp/src/sccp_scoc.c", line=line@entry=1677) at ../../../src/libosmocore/src/fsm.c:877
#21 0x00007f8ec1d950bc in sccp_scoc_rx_from_scrc (inst=inst@entry=0x558dc8118310, xua=xua@entry=0x558dc8122a90) at ../../../src/libosmo-sccp/src/sccp_scoc.c:1677
#22 0x00007f8ec1d92b1e in scrc_rx_mtp_xfer_ind_xua (inst=inst@entry=0x558dc8118310, xua=0x558dc8122a90) at ../../../src/libosmo-sccp/src/sccp_scrc.c:457
#23 0x00007f8ec1d95ccd in mtp_user_prim_cb (oph=0x558dc8180a98, ctx=0x558dc8118310) at ../../../src/libosmo-sccp/src/sccp_user.c:176
#24 0x00007f8ec1d8d62d in m3ua_rx_xfer (xua=0x558dc81824b0, asp=0x558dc811eb00) at ../../../src/libosmo-sccp/src/m3ua.c:586
#25 m3ua_rx_msg (asp=asp@entry=0x558dc811eb00, msg=msg@entry=0x558dc817fd20) at ../../../src/libosmo-sccp/src/m3ua.c:739
#26 0x00007f8ec1d9cc83 in xua_cli_read_cb (conn=0x558dc811c130) at ../../../src/libosmo-sccp/src/osmo_ss7.c:1701
#27 0x00007f8ec1fd5d93 in osmo_stream_cli_read (cli=0x558dc811c130) at ../../../src/libosmo-netif/src/stream.c:222
#28 osmo_stream_cli_fd_cb (ofd=<optimized out>, what=1) at ../../../src/libosmo-netif/src/stream.c:311
#29 0x00007f8ec200a25a in osmo_fd_disp_fds (_eset=<optimized out>, _wset=<optimized out>, _rset=<optimized out>) at ../../../src/libosmocore/src/select.c:227
#30 _osmo_select_main (polling=<optimized out>) at ../../../src/libosmocore/src/select.c:265
#31 0x00007f8ec200a826 in osmo_select_main_ctx (polling=<optimized out>) at ../../../src/libosmocore/src/select.c:291
#32 0x0000558dc62abfe3 in main (argc=<optimized out>, argv=0x7ffe75e0ba48) at ../../../../src/osmo-msc/src/osmo-msc/msc_main.c:729
</pre>
<p>the message contains invalid Mobile Identity:</p>
<pre>
(gdb) p mi_len
$8 = 8
(gdb) x/2 mi
0x558dc811f196: 0xffffffff 0xffffffff
</pre>
<p>basically all bytes are 0xff.</p> OsmoMSC - Bug #3989 (Resolved): Segmentation fault when making a MO call: Assert failed msg_type ...https://projects.osmocom.org/issues/39892019-05-08T22:40:02Zfixeria
<p>I just upgraded to the recent OsmoMSC refactoring "code bomb" patch merged. Both SMS and USSD seem to work just fine, but when I am trying to call, I am getting a segfault:</p>
<pre>
DRR DEBUG ran_peer.c:551 ran_peer(GERAN-A:RI-SSN_PC:PC-0-23-3:SSN-BSSAP)[0x1539400]{READY}: Received Event RAN_PEER_EV_MSG_UP_CO_INITIAL
DRLL DEBUG msc_a.c:1147 msc_a(unknown:GERAN-A-1:NONE)[0x15577e0]{MSC_A_ST_VALIDATE_L3}: Dispatching 04.08 message: MM GSM48_MT_MM_CM_SERV_REQ
DMM DEBUG gsm_04_08.c:738 msc_a(TMSI-0x765C0CA7:GERAN-A-1:CM_SERVICE_REQ)[0x15577e0]{MSC_A_ST_VALIDATE_L3}: Rx CM SERVICE REQUEST cm_service_type=MO-Call
DRR DEBUG ran_conn.c:119 ran_peer(GERAN-A:RI-SSN_PC:PC-0-23-3:SSN-BSSAP)[0x1539400]{READY}: Received Event RAN_PEER_EV_MSG_DOWN_CO
DRR DEBUG ran_peer.c:551 ran_peer(GERAN-A:RI-SSN_PC:PC-0-23-3:SSN-BSSAP)[0x1539400]{READY}: Received Event RAN_PEER_EV_MSG_UP_CO
DRR DEBUG ran_peer.c:551 ran_peer(GERAN-A:RI-SSN_PC:PC-0-23-3:SSN-BSSAP)[0x1539400]{READY}: Received Event RAN_PEER_EV_MSG_UP_CO
DRLL DEBUG msc_a.c:1147 msc_a(IMSI-262073993158656:MSISDN-123456:TMSI-0x765C0CA7:GERAN-A-1:CM_SERVICE_REQ)[0x15577e0]{MSC_A_ST_AUTHENTICATED}: Dispatching 04.08 message: CC GSM48_MT_CC_SETUP
DCC DEBUG transaction.c:152 trans(CC IMSI-262073993158656:MSISDN-123456:TMSI-0x765C0CA7 callref-0x80000001 tid-8) New transaction
DCC DEBUG gsm_04_08_cc.c:2151 trans(CC IMSI-262073993158656:MSISDN-123456:TMSI-0x765C0CA7:GERAN-A-1:CM_SERVICE_REQ callref-0x80000001 tid-8) rx SETUP in state NULL
DCC DEBUG gsm_04_08_cc.c:119 trans(CC IMSI-262073993158656:MSISDN-123456:TMSI-0x765C0CA7:GERAN-A-1:CM_SERVICE_REQ callref-0x80000001 tid-8) starting guard timer with 180 seconds
DCC DEBUG gsm_04_08_cc.c:189 trans(CC IMSI-262073993158656:MSISDN-123456:TMSI-0x765C0CA7:GERAN-A-1:CM_SERVICE_REQ callref-0x80000001 tid-8) new state NULL -> INITIATED
DCC INFO gsm_04_08_cc.c:567 trans(CC IMSI-262073993158656:MSISDN-123456:TMSI-0x765C0CA7:GERAN-A-1:CM_SERVICE_REQ callref-0x80000001 tid-8) SETUP to 995
DMNCC DEBUG gsm_04_08_cc.c:233 trans(CC IMSI-262073993158656:MSISDN-123456:TMSI-0x765C0CA7:GERAN-A-1:CM_SERVICE_REQ callref-0x80000001 tid-8) tx MNCC_SETUP_IND
DMNCC DEBUG mncc_builtin.c:285 (call 80000001) Call created.
DMNCC DEBUG mncc_builtin.c:295 (call 80000001) Received message MNCC_SETUP_IND
DMNCC DEBUG mncc_builtin.c:110 (call 80000001, remote 1) Creating new remote instance.
DMNCC DEBUG mncc_builtin.c:119 (call 80000001, remote 1) Accepting call.
Assert failed msg_type == msg->msg_type gsm_04_08_cc.c:2017
</pre>
<p>Some details: I am not running OsmoMGW, and using the built-in MNCC implementation.</p>
<pre>
gdb# bt
#0 0x00007ffff60b9c37 in __GI_raise (sig=sig@entry=0x6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#1 0x00007ffff60bd028 in __GI_abort () at abort.c:89
#2 0x00007ffff7321f75 in osmo_panic_default (args=0x7fffffffa378, fmt=<optimized out>) at panic.c:49
#3 osmo_panic (fmt=<optimized out>) at panic.c:84
#4 0x00000000004656cd in mncc_tx_to_cc (net=0x760ee0, msg_type=0x108, arg=0x7fffffffa4f0) at gsm_04_08_cc.c:2017
#5 0x000000000041d32e in mncc_setup_ind (call=0x86b8e0, msg_type=0x102, setup=0x86e2f8) at mncc_builtin.c:120
#6 0x000000000041ddea in int_mncc_recv (net=0x760ee0, msg=0x86e270) at mncc_builtin.c:299
#7 0x000000000045d90d in cc_tx_to_mncc (net=0x760ee0, msg=0x86e270) at gsm_04_08_cc.c:129
#8 0x000000000045dff7 in mncc_recvmsg (net=0x760ee0, trans=0x86dd60, msg_type=0x102, mncc=0x7fffffffbd60) at gsm_04_08_cc.c:244
#9 0x000000000045fec5 in gsm48_cc_rx_setup (trans=0x86dd60, msg=0x868930) at gsm_04_08_cc.c:572
#10 0x0000000000466473 in gsm0408_rcv_cc (msc_a=0x868e20, msg=0x868930) at gsm_04_08_cc.c:2173
#11 0x000000000042834e in msc_a_up_l3 (msc_a=0x868e20, msg=0x868930) at msc_a.c:1195
#12 0x0000000000429001 in msc_a_ran_dec_from_msc_i (msc_a=0x868e20, d=0x7fffffffca10) at msc_a.c:1343
#13 0x0000000000429bba in msc_a_ran_decode_cb (msc_a_fi=0x86dc30, data=0x7fffffffca10, msg=0x7fffffffc390) at msc_a.c:1490
#14 0x000000000043cf31 in ran_decoded (ran_dec=0x7fffffffc9a0, ran_msg=0x7fffffffc390) at ran_msg.c:159
#15 0x0000000000441e2d in ran_a_decode_l3 (ran_dec=0x7fffffffc9a0, l3=0x868930) at ran_msg_a.c:854
#16 0x00000000004420a7 in ran_a_decode_l2 (ran_dec=0x7fffffffc9a0, bssap=0x868930) at ran_msg_a.c:878
#17 0x0000000000423812 in msc_role_ran_decode (fi=0x86dc30, an_apdu=0x7fffffffd390, decode_cb=0x429a2c <msc_a_ran_decode_cb>,
decode_cb_data=0x7fffffffca10) at msub.c:589
#18 0x0000000000423dd4 in msc_a_ran_dec (msc_a=0x868e20, an_apdu=0x7fffffffd390, from_role=MSC_ROLE_I) at msc_a.c:171
#19 0x0000000000425798 in msc_a_fsm_authenticated (fi=0x86dc30, event=0xa, data=0x7fffffffd390) at msc_a.c:460
#20 0x00007ffff731b560 in _osmo_fsm_inst_dispatch (fi=0x86dc30, event=0xa, data=0x7fffffffd390, file=0x48e5c6 "msc_i.c", line=0x55)
at fsm.c:818
#21 0x0000000000422e37 in _msub_role_dispatch (msub=0x869d40, to_role=MSC_ROLE_A, to_role_event=0xa, an_apdu=0x7fffffffd390,
file=0x48e5c6 "msc_i.c", line=0x55) at msub.c:449
#22 0x000000000042bb94 in msc_i_ready_decode_cb (msc_i_fi=0x86da60, data=0x7fffffffd390, msg=0x7fffffffcc00) at msc_i.c:85
#23 0x000000000043cf31 in ran_decoded (ran_dec=0x7fffffffd210, ran_msg=0x7fffffffcc00) at ran_msg.c:159
#24 0x0000000000441e2d in ran_a_decode_l3 (ran_dec=0x7fffffffd210, l3=0x868930) at ran_msg_a.c:854
#25 0x00000000004420a7 in ran_a_decode_l2 (ran_dec=0x7fffffffd210, bssap=0x868930) at ran_msg_a.c:878
#26 0x0000000000423812 in msc_role_ran_decode (fi=0x86da60, an_apdu=0x7fffffffd390, decode_cb=0x42bb01 <msc_i_ready_decode_cb>,
decode_cb_data=0x7fffffffd390) at msub.c:589
#27 0x000000000042bd4f in msc_i_fsm_ready (fi=0x86da60, event=0xa, data=0x7fffffffd390) at msc_i.c:110
#28 0x00007ffff731b560 in _osmo_fsm_inst_dispatch (fi=0x86da60, event=0xa, data=0x7fffffffd390, file=0x497d49 "ran_peer.c", line=0x170)
at fsm.c:818
#29 0x000000000044597f in ran_peer_st_ready (fi=0x86b7b0, event=0x2, data=0x7fffffffd4d0) at ran_peer.c:368
#30 0x00007ffff731b560 in _osmo_fsm_inst_dispatch (fi=0x86b7b0, event=0x2, data=0x7fffffffd4d0, file=0x497d49 "ran_peer.c", line=0x227)
at fsm.c:818
--Type <RET> for more, q to quit, c to continue without paging--
#31 0x000000000044615e in ran_peer_up_l2 (sri=0x853640, calling_addr=0x0, co=0x1, conn_id=0x2, l2=0x868930) at ran_peer.c:551
#32 0x000000000040ae31 in sccp_ran_sap_up (oph=0x8689b8, _scu=0x853740) at sccp_ran.c:110
#33 0x00007ffff731b560 in _osmo_fsm_inst_dispatch (fi=0x86cf90, event=0xb, data=data@entry=0x850430,
file=file@entry=0x7ffff6c97697 "sccp_scoc.c", line=line@entry=0x68d) at fsm.c:818
#34 0x00007ffff6c871c1 in sccp_scoc_rx_from_scrc (inst=inst@entry=0x853520, xua=xua@entry=0x850430) at sccp_scoc.c:1677
#35 0x00007ffff6c84c30 in scrc_rx_mtp_xfer_ind_xua (inst=inst@entry=0x853520, xua=0x850430) at sccp_scrc.c:457
#36 0x00007ffff6c87e15 in mtp_user_prim_cb (oph=0x86aab8, ctx=0x853520) at sccp_user.c:176
#37 0x00007ffff6c7fd74 in m3ua_rx_xfer (xua=0x86d940, asp=0x84d3b0) at m3ua.c:586
#38 m3ua_rx_msg (asp=asp@entry=0x84d3b0, msg=msg@entry=0x86c4a0) at m3ua.c:739
#39 0x00007ffff6c8e67b in xua_cli_read_cb (conn=0x853350) at osmo_ss7.c:1650
#40 0x00007ffff7104d63 in osmo_stream_cli_read (cli=0x853350) at stream.c:213
#41 osmo_stream_cli_fd_cb (ofd=0x853350, what=0x1) at stream.c:297
#42 0x00007ffff7316cb4 in osmo_fd_disp_fds (_eset=0x7fffffffda40, _wset=0x7fffffffd9c0, _rset=0x7fffffffd940) at select.c:223
#43 osmo_select_main (polling=0x0) at select.c:263
#44 0x00000000004098dc in main (argc=0x3, argv=0x7fffffffdc48) at msc_main.c:744
#45 0x00007ffff60a4f45 in __libc_start_main (main=0x4090dc <main>, argc=0x3, argv=0x7fffffffdc48, init=<optimized out>, fini=<optimized out>,
rtld_fini=<optimized out>, stack_end=0x7fffffffdc38) at libc-start.c:287
#46 0x0000000000408979 in _start ()
</pre> OsmoBTS - Feature #3906 (Resolved): Automatically adjust LAPDm timer values with 'fn-advance' par...https://projects.osmocom.org/issues/39062019-04-06T18:19:30Zfixeria
<p>Currently we use fn-advance=20 by default, so the burst scheduler is working 20 TDMA frames in advance. This advance gives the transceiver some time to receive a burst, process it (i.e. modulate), and send to the Tx buffer of SDR. As a side effect, this increases the delay between UL and DL: 20 TDMA frames => 92.3ms of delay.</p>
<p>Higher fn-advance values cause a longer delay, resulting in LAPDm frame retransmissions.<br />OsmoBTS should automatically adjust LAPDm timer values with the configured 'fn-advance' value.</p> Cellular Network Infrastructure - Bug #3457 (Resolved): docker-playground: repository 'laforge/de...https://projects.osmocom.org/issues/34572018-08-08T19:05:57Zfixeria
<p>There is a problem appearing when building Docker images based on 'laforge/debian-jessie-build'...</p>
<p>After building, the 'debian-jessie-build' image is being tagged according to the following rule:</p>
<pre>
$(USER)/$(IMAGE) # e.g. user/debian-jessie-build
</pre>
<p>so, <strong>if the current $(USER) != 'laforge', build fails</strong>:</p>
<pre>
make[1]: Leaving directory `/home/user/osmocom/docker-playground/debian-jessie-build'
make -C osmo-stp-master
make[1]: Entering directory `/home/user/osmocom/docker-playground/osmo-stp-master'
docker build --build-arg USER=user -t docker.io/user/osmo-stp-master:latest .
Sending build context to Docker daemon 9.216kB
Step 1/16 : FROM laforge/debian-jessie-build
repository laforge/debian-jessie-build not found: does not exist or no pull access
make[1]: *** [docker-build] Error 1
make[1]: Leaving directory `/home/user/osmocom/docker-playground/osmo-stp-master'
make: *** [osmo-stp-master] Error 2
</pre>
<p>because <strong>there is no 'laforge/debian-jessie-build'</strong>, there are:</p>
<pre>
# docker image ls
REPOSITORY TAG IMAGE ID CREATED SIZE
user/debian-jessie-build latest 1f6421af8bfc 15 minutes ago 621MB
debian jessie 79f4bda91989 3 weeks ago 127MB
</pre>
<p>I started to think, may we parametrize the 'FROM laforge/debian-jessie-build' somehow?<br />Fortunately, yes! The following header makes the trick:</p>
<pre>
ARG USER
FROM $USER/debian-jessie-build
</pre>
<p>A change will be sent soon...</p> OsmoMSC - Bug #3294 (Stalled): transaction: refactor callref allocationhttps://projects.osmocom.org/issues/32942018-05-26T17:51:04Zfixeria
<p>Each transaction has a field called 'callref', that should contain an unique identifier. This identifier is being assigned either by OsmoMSC itself, either by an external application (e.g. LCR), and is used to distinguish between multiple allocated transactions.</p>
<p>In case of a new callref generation on the MSC side, there are the following sources for that:</p>
<pre>
$ git grep "static uint32_t new_callref"
src/libmsc/gsm_04_08.c:static uint32_t new_callref = 0x80000001;
src/libmsc/gsm_04_11.c:static uint32_t new_callref = 0x40000001;
src/libmsc/mncc_builtin.c:static uint32_t new_callref = 0x00000001;
</pre>
<p>So, we have a few ranges for different types of communication:</p>
<pre><code>- from 0x00000001 to 0x40000000 - Call Control, internal MNCC;<br /> - from 0x40000001 to 0x80000000 - SMS messages;<br /> - from 0x80000001 to 0xffffffff - Call Control, external MNCC;</code></pre>
<p>And this is how a new 'callref' value is generated:</p>
<pre>
new_callref++
</pre>
<p>I see the following problems:</p>
<p>1) Imagine that we have a network, which is running for some long time. What if the amount of calls ever made would reach 0x40000000? The next values will be 0x40000001, 0x40000002, 0x40000003, etc. At some point, this may result into collisions, e.g. two transactions with same 'callref' value.</p>
<p>Possible solution: instead of doing `new_callref++` manually, create a function (e.g. trans_gen_ref), which would prevent overlaps between ranges, and flush the source to initial value.</p>
<p>2) The trans_alloc(), which is used to allocate a new transactions, doesn't check if passed 'callref' value is not used. In other words, it is possible to allocate a few transactions with not unique 'callref'. In this case the trans_find_by_callref() would work incorrectly.</p>
<p>Possible solution: before allocation, check if given 'callref' is already used.</p>
<p>3) The 'callref' as a field name itself looks/sounds like something call related, while this feature will be also used as soon as we implement SMS and SS/USSD over GSUP. It would be better to rename it to something more generic, e.g. just 'ref'.</p>
<p>4) Both sides, i.e. MSC and an external application, are involved in 'callref' generation. There is no master-slave relation... This may result in a situation, when an external application asks to allocate a new transaction with 'callref', which is already used.</p>
<p>Possible solution: inspire by GSM TS 04.07, section 11.2.3 "Transaction identifier" and introduce the direction bit. Probably, this can be a bit simplified, e.g. '0' means allocated by the MSC itself, '1' - by an external application.</p> libosmocore - Bug #2986 (Resolved): GNU TLS fallback: segfault on gnutls_rnd()https://projects.osmocom.org/issues/29862018-02-22T18:42:08Zfixeria
<p>According to the GNU TLS documentation, prior to 3.3.0 the library has to be<br />initialized by calling gnutls_global_init():</p>
<p><a class="external" href="https://www.gnutls.org/manual/html_node/Initialization.html">https://www.gnutls.org/manual/html_node/Initialization.html</a></p>
<p>while the recent versions are being initialized on load. This causes<br />segfault on osmo_get_rand_id() if a library version is lower than 3.3.0...</p>
<p>At the same time, in the configure.am we require gnutls >= 2.12.0.</p> OsmoBTS - Bug #2223 (Closed): common/power_control.c: strange conditionshttps://projects.osmocom.org/issues/22232017-05-04T10:11:31Zfixeria
<p>Look at the lchan_ms_pwr_ctrl():</p>
<pre>
int lchan_ms_pwr_ctrl(struct gsm_lchan *lchan,
const uint8_t ms_power, const int rxLevel)
{
int rx;
int cur_dBm, new_dBm, new_pwr;
struct gsm_bts *bts = lchan->ts->trx->bts;
struct gsm_bts_role_bts *btsb = bts_role_bts(bts);
const enum gsm_band band = bts->band;
// ...
/*
* What is the difference between what we want and received?
* Ignore a margin that is within the range of measurement
* and MS output issues.
*/
rx = btsb->ul_power_target - rxLevel;
if (rx >= 0 && rx < 1)
return 0;
if (rx < 0 && rx > -1) // Unreachable
return 0;
// ...
}
</pre>
<blockquote>
<p>if (rx < 0 && rx > -1)</p>
</blockquote>
<p>As rx has type int, it cannot be in range (-1; 0)...</p>
<blockquote>
<p>if (rx >= 0 && rx < 1)</p>
</blockquote>
<p>Again, the only possible value here is 0.</p>