Open Source Mobile Communications: Issueshttps://osmocom.org/https://osmocom.org/favicon.ico?16647414092024-02-05T09:25:36ZOpen Source Mobile Communications
Redmine Cellular Network Infrastructure - Bug #6352 (Stalled): ttcn3-bts-test[-latest] is broken since Fe...https://osmocom.org/issues/63522024-02-05T09:25:36Zfixeria
<p>ttcn3-bts-test[-latest] is failing for a few days already:</p>
<p><a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test/2293/">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test/2293/</a><br /><a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test-latest/1953/">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test-latest/1953/</a></p>
<p>The console log (<a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test/2293/console">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test/2293/console</a>) tells us about problems with the virtphy:</p>
<pre>
+ docker kill jenkins-ttcn3-bts-test-2293-virtphy
Error response from daemon: Cannot kill container: jenkins-ttcn3-bts-test-2293-virtphy: No such container: jenkins-ttcn3-bts-test-2293-virtphy
</pre>
<p>Here is the related logging (<a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test/2293/artifact/logs/bts/osmo-bts.log">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test/2293/artifact/logs/bts/osmo-bts.log</a>):</p>
<pre>
0: starting: osmo-bts-virtual -c /data/osmo-bts.gen.cfg
((*))
|
/ \ OsmoBTS
20240201061853485 DLGLOBAL NOTICE Unimplemented bts_model_phy_instance_set_defaults (main.c:156)
20240201061853485 DLGLOBAL NOTICE Unimplemented bts_model_phy_instance_set_defaults (main.c:156)
20240201061853485 DLGLOBAL NOTICE Unimplemented bts_model_phy_instance_set_defaults (main.c:156)
20240201061853485 DLGLOBAL NOTICE Unimplemented bts_model_phy_instance_set_defaults (main.c:156)
20240201061853486 DLGLOBAL NOTICE Setting up GSMTAP Um forwarding '(null)->'172.18.29.10:4729' (main.c:363)
20240201061853486 DLCTRL NOTICE CTRL at 0.0.0.0 4238 (control_if.c:1014)
20240201061853487 DL1C NOTICE Unimplemented bts_model_ctrl_cmds_install (bts_model.c:222)
20240201061853487 DLGLOBAL NOTICE Available via telnet 0.0.0.0 4241 (telnet_interface.c:88)
20240201061853487 DPCU INFO Started listening on PCU socket (PCU IF v12): /data/unix/pcu_sock (pcu_sock.c:1237)
20240201061853487 DOSMUX INFO Osmux socket listening on 172.18.29.20:1984 (osmux.c:352)
20240201061853487 DABIS NOTICE A-bis connection establishment to BSC (127.0.0.11) in progress... (abis.c:161)
20240201061853487 DLINP NOTICE enabling ipaccess BTS mode, OML connecting to 127.0.0.11:3002 (ipaccess.c:1098)
20240201061853487 DL1C INFO phy0: PHY link state change shutdown -> connecting (phy_link.c:58)
Failed to join to mcast goup: No such device
Unable to create VirtualUm multicast socket: No such device
20240201061853487 DL1C INFO phy0: PHY link state change connecting -> shutdown (phy_link.c:58)
unable to open PHY link(s)
0: stopped pid 8 with status 2
</pre>
<p>The virtphy container (<a class="external" href="https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test/2293/artifact/logs/virtphy/virtphy.log">https://jenkins.osmocom.org/jenkins/view/TTCN3/job/ttcn3-bts-test/2293/artifact/logs/virtphy/virtphy.log</a>) fails to start:</p>
<pre>
Thu Feb 1 06:18:53 2024 DVIRPHY virtphy.c:248 Virtual physical layer starting up...
Failed to join to mcast goup: No such device
Unable to create VirtualUm multicast socket: No such device
Segmentation fault (core dumped)
</pre> pySim - Bug #6317 (Stalled): data driven tests for TLV decodershttps://osmocom.org/issues/63172023-12-23T15:12:32Zlaforge
<p>While we do have the <code>_test_de_encode</code> data driven tests for file definitions, we don't yet have something similar for derived classes of BER_TLV_IE. This means that TLVs used outside of the filesystem context (for example, decoding the SELECT/STATUS response, but also eUICC and other stuff) do not yet have test coverage.</p> pySim - Bug #5714 (Stalled): update_record_decoded does not use real record length when writing E...https://osmocom.org/issues/57142022-10-16T08:44:29ZCHV
<p>I'm using old regular cards for testing.</p>
<p>Class EF_MSISDN, method _encode_record_hex always assumes a rec_len of 15 which results in misaligned/invalid data if the real record length is different.<br />The encoded msisdn must always use the <ins>last 14 bytes</ins> in the record. This can only be achieved when the real record length is used.</p>
<p>Example:<br /><pre>
select MF/ADF.USIM/EF.MSISDN
update_record_decoded 1 {"msisdn":"+491234567890"}
read_record_decoded 1
read_record 1
</pre></p>
<p>This may also concern updating EF.ADN records.</p> OsmoPCU - Bug #5696 (Stalled): RLC/MAC: poll timeout when assigning a multi-slot DL TBFhttps://osmocom.org/issues/56962022-10-05T07:58:36Zfixeria
<p>One of my phones, Sony Ericsson K800i, fails to complete <code>PDP Context Activation</code> procedure. Thanks to TEMS, I found out that the phone never receives <code>Activate PDP Context Accept</code> message. Further analysis revealed that <code>Activate PDP Context Request</code> message from the phone triggers allocation of a multi-slot Downlink TBF, which includes TS6 and TS7. For some reason, <strong>the phone ACKnowledges allocation of Downlink TBF on TS7 instead of TS6</strong>, what confuses osmo-pcu and causes retransmissions of the <code>PACKET_DOWNLINK_ASSIGNMENT</code> message.</p> OCTOI - Osmocom Community TDM over IP - Bug #5694 (Stalled): BERT testinghttps://osmocom.org/issues/56942022-10-01T06:59:48Zlaforge
<p>Soem initial tests with a PrTel93i doing BERT testing on a single B-channel indicates we have some problems to investigate.</p>
<p>This ticket serves as log of the various tests/attempts so far</p>
<ul>
<li>PrTel93i against same PrTel93i doing internal call through Auerswald COMmander2 PBX
<ul>
<li>0 errors in several 1min and 15min calls. So the PrTel and the wiring are good.</li>
</ul></li>
</ul>
<ul>
<li>PrTel93i against same PrTel93i doing external call through same PBX but going out via icE1usb to OCTOI hub and calling back through the same path:
<ul>
<li>first 1min call was with 0 errors</li>
<li>first 15min call was with 6.62 E-2 BER</li>
<li>second 15min call was with 5.92 E-2 BER</li>
<li>no lost / reordered OCTOI frames observed during that time</li>
</ul></li>
</ul>
<ul>
<li>PrTel93i against bchan_loop from capi-hacks (hfc-usb, mISDN, CAPI20) doing internal call through Auerswald COMmander2 PBX
<ul>
<li>1min call with 4.25 E-1 BER</li>
<li>so clearly there are some problems in the misdn/capi integration</li>
</ul></li>
</ul> OCTOI - Osmocom Community TDM over IP - Bug #5693 (Stalled): no progress tones in yatehttps://osmocom.org/issues/56932022-09-30T13:04:16Zlaforge
<p>We've never had call progress tones from yate in our network and had ignored that until now.</p>
This is the case in
<ul>
<li>any outbound call setup from a phone, where there are no dial tones, alerting tones, etc.</li>
<li>calls routed to tone/*</li>
</ul>
<p>The respective ToneSource() class instances are created and provide the respective quantity of samples. It works for SIP, but not for ISDN.</p>
<p>I think it's related to the Q.931 signaling side. It states:</p>
<blockquote>
<p><strong>5.4 In-band tones and announcements</strong></p>
<p>When in-band tones/announcements not associated with a call state change are to be provided by the network before reaching the Active state, a PROGRESS message is returned simultaneously with the application of the in-band tone/announcement. The PROGRESS message contains the progress indicator No. 8, in-band information or appropriate pattern is now available.</p>
<p>When tones/announcements have to be provided together with a call state change, then the appropriate message [e.g. for ALERTING, DISCONNECT, etc., (see clause 3)] with progress indicator No. 8, in-band information or appropriate pattern is now available, is sent simultaneously with the application of the in-band tone/announcement.</p>
</blockquote> Core testing infrastructure - Bug #5665 (Stalled): ERROR: files left in build directory after dis...https://osmocom.org/issues/56652022-08-28T09:21:41Zfixeria
<p>Since recently we're observing sporadic master-* job failures on Jenkins. There is always a coredump file, which makes 'distcleancheck' target fail:</p>
<pre>
ERROR: files left in build directory after distclean:
./tests/core
make[1]: Leaving directory '/build/libosmocore-1.7.0.26-862dd/_build/sub'
make[1]: *** [Makefile:1010: distcleancheck] Error 1
make: *** [Makefile:941: distcheck] Error 1
</pre>
<p>This is not specific to libosmocore, I saw master-osmo-{bsc,msc} failing with the same verdict too.</p> pySim - Bug #5630 (Stalled): pySim-trace doesn't support decoding classic SIM cards (TS 11.11 / T...https://osmocom.org/issues/56302022-07-24T11:06:35Zlaforge
<p>pySim-trace currently doesn't support decoding APDUs of classic SIM cards (TS 11.11 / TS 51.011) with CLA=A0.</p>
<p>I have some WIP code implementing the related ApduCommand.</p>
<p>However, there's a more critical underlying constraint in ApduCommandSet: There can only be one ApduCommand for each INS. This needs to be modified so that any number of ApduCommand can handle an INS, just as long as they each deal with their own CLA.</p> SIMtrace 2 - Bug #5578 (Stalled): osmo-remsim-client-st2 hangs after usb-reset without power loss...https://osmocom.org/issues/55782022-06-15T21:50:45Zroh
<p>in case of a osmo-remsim-client-st2 session which gets restarted after being stopped by a usb-disconnect<br /> (terminates with "DST2 FATAL user_simtrace2.c:221 USB IN transfer failed, status=1" as expected)</p>
<p>osmo-remsim-client-st2 gets stuck and then terminates after some time:</p>
<pre>
root@raspberrypi:~# /usr/bin/osmo-remsim-client-st2 -i 10.15.1.135 -V 1d50 -P 4004 -C 1 -I 0 -H 1-1.3.1 -c 1 -n 0
DRSPRO INFO ../rspro_client_fsm.c:307 RSPRO_CLIENT(server){REESTABLISH}: Creating TCP connection to server at 10.15.1.135:9998
DLINP NOTICE simtrace2_api.c:267 [0] <= osmo_st2_cardem_request_config(features=00000001)
DLINP NOTICE input/ipa.c:128 10.15.1.135:9998 connection done
DRSPRO NOTICE ../rspro_client_fsm.c:125 RSPRO_CLIENT(server){REESTABLISH}: RSPRO link to 10.15.1.135:9998 UP
DRSPRO INFO ../rspro_client_fsm.c:307 RSPRO_CLIENT(bankd){REESTABLISH}: Creating TCP connection to server at 10.15.1.135:9999
DLINP NOTICE input/ipa.c:128 10.15.1.135:9999 connection done
DRSPRO NOTICE ../rspro_client_fsm.c:125 RSPRO_CLIENT(bankd){REESTABLISH}: RSPRO link to 10.15.1.135:9999 UP
DLINP NOTICE simtrace2_api.c:168 [0] <= osmo_st2_cardem_request_card_insert(inserted=1)
DLINP NOTICE simtrace2_api.c:317 [0] <= _modem_sim_select(remote_sim=1)
DLINP NOTICE simtrace2_api.c:250 [0] <= osmo_st2_cardem_request_set_atr(3b 00 )
DLINP NOTICE simtrace2_api.c:285 [0] <= _modem_reset(asserted=2, pulse_ms=300)
DLINP NOTICE simtrace2_api.c:250 [0] <= osmo_st2_cardem_request_set_atr(3b 9f 96 80 1f 87 80 31 e0 73 fe 21 1b 67 4a 4c 75 30 34 05 4b a9 )
DST2 INFO user_simtrace2.c:65 SIMtrace => PTS req: ff 10 96 79 00 00
...
<modem starts, usb enumeration of serials/wwlan>
...
USB OUT transfer failed, status=2
</pre>
<p>later restarts remain the same in behaviour but a bit different in output:</p>
<pre>
root@raspberrypi:~# /usr/bin/osmo-remsim-client-st2 -i 10.15.1.135 -V 1d50 -P 4004 -C 1 -I 0 -H 1-1.3.1 -c 1 -n 0
DRSPRO INFO ../rspro_client_fsm.c:307 RSPRO_CLIENT(server){REESTABLISH}: Creating TCP connection to server at 10.15.1.135:9998
DLINP NOTICE simtrace2_api.c:267 [0] <= osmo_st2_cardem_request_config(features=00000001)
DLINP NOTICE input/ipa.c:128 10.15.1.135:9998 connection done
DRSPRO NOTICE ../rspro_client_fsm.c:125 RSPRO_CLIENT(server){REESTABLISH}: RSPRO link to 10.15.1.135:9998 UP
DRSPRO INFO ../rspro_client_fsm.c:307 RSPRO_CLIENT(bankd){REESTABLISH}: Creating TCP connection to server at 10.15.1.135:9999
DLINP NOTICE input/ipa.c:128 10.15.1.135:9999 connection done
DRSPRO NOTICE ../rspro_client_fsm.c:125 RSPRO_CLIENT(bankd){REESTABLISH}: RSPRO link to 10.15.1.135:9999 UP
DLINP NOTICE simtrace2_api.c:168 [0] <= osmo_st2_cardem_request_card_insert(inserted=1)
DLINP NOTICE simtrace2_api.c:317 [0] <= _modem_sim_select(remote_sim=1)
DLINP NOTICE simtrace2_api.c:250 [0] <= osmo_st2_cardem_request_set_atr(3b 00 )
DLINP NOTICE simtrace2_api.c:285 [0] <= _modem_reset(asserted=2, pulse_ms=300)
DLINP NOTICE simtrace2_api.c:250 [0] <= osmo_st2_cardem_request_set_atr(3b 9f 96 80 1f 87 80 31 e0 73 fe 21 1b 67 4a 4c 75 30 34 05 4b a9 )
USB OUT transfer failed, status=2
</pre>
<p>please note that the modem does not seem to reboot on later restarts of osmo-remsim-client-st2, which is odd.</p>
<p>osmo-remsim-client version 1.0.0.18-f5f5<br />qmod firmware 0.8.1.33-9088</p>
<p>osmo-remsim-bankd version 1.0.0.18-f5f5<br />osmo-resmim-server version 1.0.0.18-f5f5</p>
<p>maybe this is a rerun of <a class="issue tracker-1 status-7 priority-1 priority-lowest" title="Bug: osmo-remsim-client-st2 (or firmware?) gets stuck on PTS (Stalled)" href="https://osmocom.org/issues/4409">#4409</a></p>
<p>for this test the server/bankd were on x86_64 and the client was on armv7l (rpi) but i don't think it matters.<br />i have also tried a older qmod firmware (0.7.0.57-f46d) for comparison but i can see no difference in behavior.</p>
<p>please note that i could not reproduce this issue with a modem on st34, only on st12. i suspect it has to do with st12 staying powered all the time and not reset/rebooted on usb-connect properly somehow.</p>
<p>this may as well be a firmware issue on the qmod.</p> OsmoMSC - Bug #5568 (Stalled): SMPP socket doesn't use TCP_NODELAYhttps://osmocom.org/issues/55682022-05-17T18:33:30Zlaforge
<p>The SMPP socket uses sockets directly (without relying on libosmo-netif/stream) and fails to setsockopt(TCP_NODELAY). This is not critical (SMS is sloooow), but it does add unintended latency to all SMPP messages sent.</p>
<p>The quick fix is to add the setsockopt for every socket we accept(). The clean-up would be to use libosmo-netif/stream...</p> OsmoMSC - Bug #5564 (Stalled): blocking database I/O by SMS databasehttps://osmocom.org/issues/55642022-05-15T14:18:42Zlaforge
<p>when OsmoMSC was split from OsmoNITB, we externalized the HLR database and removed the database-stored counters. This leaves the internal SMS queue / database code as the only remaining part of code which performs potentailly blocking disk I/O.</p>
<p>As seen in <a class="issue tracker-1 status-7 priority-3 priority-high3" title="Bug: OsmoMSC sometimes stalls for dozens of seconds in a production deployment (Stalled)" href="https://osmocom.org/issues/5563">#5563</a> this is a real issue.</p>
I spent half a day on reviewing the code in detail and playing with different ideas, including
<ol>
<li>ripping out the sms_queue.c / db.c code completely into an external osmo-smsc which then uses GSUP</li>
<li>just moving db.c into a separate thread; make DB operations asynchronous</li>
<li>move sms_queue + db.c into a separate thread</li>
</ol>
<a name="moving-sms_queue-DB-code-to-new-osmo-smsc-intrfaced-via-GSUP"></a>
<h2 >moving sms_queue + DB code to new osmo-smsc, intrfaced via GSUP<a href="#moving-sms_queue-DB-code-to-new-osmo-smsc-intrfaced-via-GSUP" class="wiki-anchor">¶</a></h2>
<p>osmo-msc already contains code to do SMS via GSUP, so there's no mandatory modification to osm-msc expected in this approach.</p>
the major disadvantages of this appraoch are:
<ul>
<li>SMPP code would have to move to SMSC, and it is more tied into the MSC/VLR codebase -> extra effort</li>
<li>GSUP SMS interface is at a lower level than current sms_queue intrface -> extra effort of migrating/reimplementing that stuff in SMSC</li>
</ul>
<a name="SMS-related-VTY-commands-not-an-issue-SMSC-would-have-its-own-VTY"></a>
<h3 >SMS related VTY commands (not an issue, SMSC would have its own VTY)<a href="#SMS-related-VTY-commands-not-an-issue-SMSC-would-have-its-own-VTY" class="wiki-anchor">¶</a></h3>
<p>this would cover the following API parts</p>
<ul>
<li>sms_queue_clear</li>
<li>sms_queue_set_max_failure</li>
<li>sms_queue_set_max_pending</li>
<li>sms_queue_stats</li>
<li>sms_queue_sms_is_pending</li>
<li>sms_queue_trigger</li>
<li>vty_out</li>
</ul>
<a name="incoming-signals-into-sms_queue"></a>
<h3 >incoming signals into sms_queue<a href="#incoming-signals-into-sms_queue" class="wiki-anchor">¶</a></h3>
<ul>
<li>SS_SUBSCR / S_SUBSCR_ATTACHED
<ul>
<li>FIXME: unclear how this is handled in the GSUP case?</li>
</ul>
</li>
<li>SS_SMS / S_SMS_DELIVERED
<ul>
<li>-> gsm411_gsup_mt_fwd_sm_res()</li>
</ul>
</li>
<li>SS_SMS / S_SMS_MEM_EXCEEDED
<ul>
<li>-> gsm411_gsup_mt_fwd_sm_err()</li>
</ul>
</li>
<li>SS_SMS / S_SMS_UNKNOWN_ERROR
<ul>
<li>-> gsm411_gsup_mt_fwd_sm_err()</li>
</ul>
</li>
<li>SS_SMS / S_SMS_SUBMITTED
<ul>
<li>-> gsm411_gsup_mo_fwd_sm_req()</li>
</ul>
</li>
<li>SS_SMS / S_SMS_SMMA
<ul>
<li>-> gsm411_gsup_mo_ready_for_sm_req()</li>
</ul></li>
</ul>
<a name="DB-not-an-issue-DB-code-would-then-run-in-SMSC"></a>
<h3 >DB (not an issue, DB code would then run in SMSC)<a href="#DB-not-an-issue-DB-code-would-then-run-in-SMSC" class="wiki-anchor">¶</a></h3>
<ul>
<li>db_sms_delete_oldest_expired_message</li>
<li>db_sms_delete_sent_message_by_id</li>
<li>db_sms_get</li>
<li>db_sms_get_next_unsent_rr_msisdn</li>
<li>db_sms_get_unsent_for_subscr</li>
<li>db_sms_inc_deliver_attempts</li>
</ul>
<a name="SMS-transmission"></a>
<h3 >SMS transmission<a href="#SMS-transmission" class="wiki-anchor">¶</a></h3>
<ul>
<li>gsm411_send_sms calls by sms_queue
<ul>
<li>would have to be mapped to OSMO_GSUP_MSGT_MT_FORWARD_SM_REQUEST</li>
</ul>
</li>
<li>sms_free
<ul>
<li>FIXME: what about vsub pointer/references?</li>
</ul>
</li>
<li>vlr_subscr_msisdn_or_name
<ul>
<li>just for logging, can be avoided</li>
</ul></li>
</ul>
<a name="making-just-the-DB-code-async-run-in-separate-thread"></a>
<h2 > making just the DB code async / run in separate thread<a href="#making-just-the-DB-code-async-run-in-separate-thread" class="wiki-anchor">¶</a></h2>
Is not easy as all of the call sites are assuming synchronous return/results<br />db_sms_get
<ul>
<li>sms_resend_pending
<ul>
<li>resend_pending timer
<ul>
<li>sms_queue_start
<ul>
<li>=> can be executed from separate thread</li>
</ul></li>
</ul></li>
</ul></li>
</ul>
db_sms_get_next_unsent_rr_msisdn
<ul>
<li>smsq_take_next_sms
<ul>
<li>sms_submit_pending
<ul>
<li>sms_send_next
<ul>
<li>sms_sms_cb / S_SMS_DELIVERED
<ul>
<li>=> happens from the send_next it_Q completion handler</li>
</ul>
</li>
</ul>
</li>
<li>push_queue_timer
<ul>
<li>sms_queue_start
<ul>
<li>=> can be executed from separate thread</li>
</ul></li>
</ul></li>
</ul></li>
</ul></li>
</ul>
db_sms_get_unsent_for_subscr
<ul>
<li>sms_send_next
<ul>
<li>sms_sms_cb / S_SMS_DELIVERED
<ul>
<li>=> request to it_Q; completion then might add SMS to pending + gsm411_send_sms</li>
</ul>
</li>
</ul>
</li>
<li>sub_ready_for_sm
<ul>
<li>sms_subscr_cb / S_SUBSCR_ATTACHED
<ul>
<li>=> request to it_Q; completion then might add SMS to pending + gsm411_send_sms</li>
</ul></li>
</ul></li>
</ul>
db_sms_delete_sent_message_by_id
<ul>
<li>sms_sms_cb / S_SMS_DELIVERED
<ul>
<li>=> no return value, no success check: async it_Q</li>
</ul></li>
</ul>
db_sms_inc_deliver_attempts
<ul>
<li>sms_sms_cb / S_SMS_UNKNOWN_ERROR
<ul>
<li>=> no return value, no success check: async it_Q</li>
</ul></li>
</ul>
db_sms_delete_oldest_expired_message
<ul>
<li>sms_sms_cb / any signal
<ul>
<li>=> no return value, no success check: async it_Q</li>
</ul></li>
</ul>
<a name="moving-sms_queue-DB-code-to-separate-thread"></a>
<h2 >moving sms_queue + DB code to separate thread<a href="#moving-sms_queue-DB-code-to-separate-thread" class="wiki-anchor">¶</a></h2>
<a name="access-to-pending_sms-linked-list"></a>
<h3 >access to pending_sms linked list<a href="#access-to-pending_sms-linked-list" class="wiki-anchor">¶</a></h3>
<p>There are quite a number of accesses to the pending_sms linked list. Given most ar read, and only some are write, we might use a rwlock?</p>
<ul>
<li>sms_find_pending [R]
<ul>
<li>sms_sms_cb</li>
<li>sms_queue_sms_is_pending</li>
</ul></li>
</ul>
<ul>
<li>sms_queue_sms_is_pending [R]
<ul>
<li>sms_submit_pending
<ul>
<li>timer</li>
</ul>
</li>
<li>vty</li>
</ul></li>
</ul>
<ul>
<li>sms_subscriber_find_pending [R]
<ul>
<li>sub_ready_for_sm
<ul>
<li>SS_SUBSCR / S_SUBSCR_ATTACHED</li>
</ul>
</li>
<li>sms_subscriber_is_pending
<ul>
<li>sms_submit_pending
<ul>
<li>timer</li>
</ul>
</li>
<li>sms_send_next
<ul>
<li>sms_sms_cb / S_SMS_DELIVERED</li>
</ul></li>
</ul></li>
</ul></li>
</ul>
<ul>
<li>sms_pending_from [R]
<ul>
<li>sms_submit_pending
<ul>
<li>timer</li>
</ul>
</li>
<li>sms_send_next
<ul>
<li>sms_sms_cb / S_SMS_DELIVERED</li>
</ul></li>
</ul></li>
</ul>
<ul>
<li>sms_pending_free [W]
<ul>
<li>sms_pending_failed
<ul>
<li>sms_sms_cb / S_SMS_UNKNOWN_ERROR</li>
</ul>
</li>
<li>sms_resend_pending
<ul>
<li>sms_sms_cb / S_SMS_DELIVERED</li>
<li>sms_sms_cb / S_SMS_MEM_EXCEEDED</li>
</ul>
</li>
<li>sms_queue_clear
<ul>
<li>vty</li>
</ul></li>
</ul></li>
</ul>
<ul>
<li>sms_resend_pending [R]
<ul>
<li>timer</li>
</ul></li>
</ul>
<ul>
<li>sms_queue_stats [R]
<ul>
<li>vty</li>
</ul></li>
</ul>
<ul>
<li>sms_queue_clear [W]
<ul>
<li>vty</li>
</ul></li>
</ul>
<a name="Conclusion"></a>
<h2 >Conclusion<a href="#Conclusion" class="wiki-anchor">¶</a></h2>
I think the following approach is best:
<ul>
<li>have a separate "SMS" thread</li>
<li>all database access happens <strong>from that thread only</strong></li>
<li>inter-thread message queues (libosmocore it_q) between main thread and SMS thread</li>
<li>sms_queue timers (push_queue_timer, resend_pending_timer) run in that thread</li>
<li>other input (mainly signals today) are serialized via it_q in main -> SMS direction</li>
<li>other output (mainly gsm411_send_sms) are serialized via it_q in SMS -> main direction</li>
</ul>
<a name="Serialize-SS_SMS-signals"></a>
<h3 >Serialize SS_SMS signals<a href="#Serialize-SS_SMS-signals" class="wiki-anchor">¶</a></h3>
<ul>
<li>we really only need to serialize paging_result and sms->id</li>
<li>submit them into it_q to SMS thread</li>
</ul>
<a name="serialize-SS_SUBSCR-signal"></a>
<h3 >serialize SS_SUBSCR signal<a href="#serialize-SS_SUBSCR-signal" class="wiki-anchor">¶</a></h3>
<ul>
<li>sms_subscriber_find_pending() can be done in main thread before serialization</li>
<li>check for vsub->lu_complete and zero MSISDN before serialization</li>
<li>we really only need to serialize the MSISDN</li>
<li>db_sms_get_unsent_for_subscr() then happens from SMS thread</li>
</ul>
<a name="move-push_queue_timer-resend_pending_timer-to-SMS-thread"></a>
<h3 >move push_queue_timer + resend_pending_timer to SMS thread<a href="#move-push_queue_timer-resend_pending_timer-to-SMS-thread" class="wiki-anchor">¶</a></h3>
<a name="serialize-db_sms_store-MO-SMS-SMPP"></a>
<h3 >serialize db_sms_store() (MO-SMS, SMPP)<a href="#serialize-db_sms_store-MO-SMS-SMPP" class="wiki-anchor">¶</a></h3>
<ul>
<li>failure to store in database would only be known asynchronously!</li>
<li>we can probably just ignore that.</li>
</ul>
<a name="serialize-db_sms_mark_delivered"></a>
<h3 >serialize db_sms_mark_delivered()<a href="#serialize-db_sms_mark_delivered" class="wiki-anchor">¶</a></h3>
<ul>
<li>we don't care about success right now anyway, so async is no problem</li>
</ul>
<a name="VTY"></a>
<h3 >VTY<a href="#VTY" class="wiki-anchor">¶</a></h3>
<ul>
<li>remove 'sms send pending' or implement different command via it_Q</li>
<li>remove 'sms delete expired' or implement different command via it_Q</li>
<li>serialize 'subscriber ... sms ...' via it_Q</li>
</ul> OsmoMSC - Bug #5563 (Stalled): OsmoMSC sometimes stalls for dozens of seconds in a production dep...https://osmocom.org/issues/55632022-05-14T07:02:28Zlaforge
<p>When we take a long-term (8 hours) bpftrace showing us the delay between subsequent calls to <code>poll()</code> (by libosmocore/src/select.c) in osmo-msc, we get the following histogram (units in milli-seconds):</p>
<pre>
@poll:
[0] 532245 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
[1] 13088 |@ |
[2, 4) 5621 | |
[4, 8) 5566 | |
[8, 16) 2746 | |
[16, 32) 5282 | |
[32, 64) 5262 | |
[64, 128) 6139 | |
[128, 256) 14273 |@ |
[256, 512) 18357 |@ |
[512, 1K) 13806 |@ |
[1K, 2K) 4222 | |
[2K, 4K) 1331 | |
[4K, 8K) 450 | |
[8K, 16K) 0 | |
[16K, 32K) 0 | |
[32K, 64K) 5 | |
[64K, 128K) 17 | |
[128K, 256K) 2 | |
</pre>
So as we can see
<ul>
<li>the majority is very low (sub-second to 128ms)</li>
<li>there is a smaller peak in the order of 128ms to 1s (surprisingly long)</li>
<li>there are still several thousand of instances where the delay isn the 1s..4s. interval (too long!)</li>
<li>there ar rare occasions where we don't return to poll for 32, 64, or evne more than 128 seconds (crazy!)</li>
</ul>
<p>If we contrast this with the amount of time we spent in <code>dbi_conn_queryf</code>, this is clearly not the culprit:</p>
<pre>
@dbi_query:
[0] 37008 |@ |
[1] 1640233 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
[2, 4) 1245771 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |
[4, 8) 21406 | |
[8, 16) 325 | |
[16, 32) 71 | |
[32, 64) 17 | |
</pre>
<p>So the longest duration DB query was in the order of 32..63 ms. Not good, but not a problem either with all the MSC (MM, CC, SMS, BSSAP, SCCP, ...) time-outs being in the multiple-second range.</p>
<p>So now we have to find out if the stalls are</p>
<ol>
<li>due to excessive system load (like I/O) outside of osmo-msc, or</li>
<li>due to something osmo-msc is doing by itself (like calling thousands of database queries of several milli-seconds each) without going through the libosmocore poll main loop.</li>
</ol> OsmoMSC - Bug #5559 (Stalled): OsmoMSC at 100% CPU and unresponsive for up to several minutes!https://osmocom.org/issues/55592022-05-12T23:22:09Zkeith
<p>Not much more to say than the title I'm afraid.</p>
<p>So far, I've actually only noticed it on a system using the RBS and osmo-e1d. But I do not have conclusive proof that it is exclusively happening here.</p>
<p>I'm assuming a culprit might be the sms queue, but I'm not convinced because I'm not seeing it on other systems with more messages in the queue in the sqlite db - and this can be upwards of 1,000 SMS queued.</p> osmo-remsim - Bug #5527 (Stalled): warn on duplicate client (id) connectionshttps://osmocom.org/issues/55272022-04-12T17:37:27Zlaforge
<p>Every client must have its own unique tuple of (client_id/slot_nr).</p>
<p>If a remsim-server receives a duplicate connection, it should pring a clear warning message to the log.</p>
<p>This might not always be a bug, as in csae of network outages / restarts a new connection might arrive before the old one is closed.</p>
<p>The same should apply to remsim-bankd.</p> SIMtrace 2 - Bug #5419 (Stalled): cardem errors with higher baud ratehttps://osmocom.org/issues/54192022-01-25T18:27:00Zlaforge
Setup is as follows:
<ul>
<li>sysmoISIM-SJA2 in built-in CCID reader of my Thinkpad x260</li>
<li>SIMtrace2 with cardem firmware 'master' (0.8.1.7-ea9a) hooked up via FPC to</li>
<li>CCID reader "Identive CLOUD 2700 F" </li>
<li><code>simtrace2-cardem-pcsc</code> to forward request from IdentiveCCID -> SIMtrace -> st2-cardem-pcsc -> builtin-CCID</li>
</ul>
<p>This works fine with F/D ratio 372, and also works fine in most cases with F/D ratio 16.</p>
<p>However, sometimes with ratio 16, things break down at some point.</p>
<a name="log-output-of-cardem-firmware"></a>
<h2 >log output of cardem firmware<a href="#log-output-of-cardem-firmware" class="wiki-anchor">¶</a></h2>
<pre>
-I- 0: flush_rx_buffer (5)
-I- 0: send_tpdu_header: 00 b2 9d 04 22
-I- 0: flush_rx_buffer (5)
-I- 0: send_tpdu_header: 00 a4 00 04 02
-I- 0: flush_rx_buffer (5)
-I- 0: flush_rx_buffer (2)
-I- 0: send_tpdu_header: 00 c0 00 00 23
-I- 0: flush_rx_buffer (5)
-I- 0: send_tpdu_header: 00 b2 9e 04 22
-I- 0: flush_rx_buffer (5)
-I- 0: send_tpdu_header: 00 a4 00 04 02
-I- 0: flush_rx_buffer (5)
-I- 0: flush_rx_buffer (2)
-I- 0: send_tpdu_header: 00 c0 00 00 23
-I- 0: flush_rx_buffer (5)
-I- 0: send_tpdu_header: 00 b2 9f 04 22
-I- 0: flush_rx_buffer (5)
-I- 0: send_tpdu_header: 00 a4 00 04 02
-I- 0: flush_rx_buffer (5)
-I- 0: flush_rx_buffer (2)
-I- 0: send_tpdu_header: 00 c0 00 00 23
-I- 0: flush_rx_buffer (5)
-I- 0: send_tpdu_header: 00 b2 a0 04 22
-I- 0: flush_rx_buffer (5)
-I- 0: send_tpdu_header: 00 a4 00 04 02
-I- 0: flush_rx_buffer (5)
-I- 0: flush_rx_buffer (2)
-I- 0: send_tpdu_header: 00 c0 00 00 23
-I- 0: flush_rx_buffer (5)
N-I- 0: send_tpdu_header: 00 b2 a1 04 22
-I- 0: flush_rx_buffer (5)
-I- 0: send_tpdu_header: 00 a4 00 04 02
-I- 0: flush_rx_buffer (5)
-I- 0: flush_rx_buffer (2)
N-I- 0: send_tpdu_header: 00 c0 00 00 60
-I- 0: flush_rx_buffer (5)
-I- 0: send_tpdu_header: 02 00 a4 00 04
-I- 0: flush_rx_buffer (5)
</pre>
two things noticable:
<ul>
<li>the 'N' being printed by card_emu as waiting time extension</li>
<li>the last TPDU header <code>02 00 a4 00 04</code> doesn't look like a TPDU header: The 02 seems wrong, the TPDU likely starts with <code>00 a4</code>.</li>
</ul>
<a name="situation-on-Identive-CCID-reader-side"></a>
<h2 >situation on "Identive CCID reader" side<a href="#situation-on-Identive-CCID-reader-side" class="wiki-anchor">¶</a></h2>
<p>pySim-shell "export" shows:<br /><pre>
update_record 159 ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff
update_record 160 ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff
update_record 161 ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff
# bad file: MF/DF.TELECOM/EF.ADN, Failed to transmit with protocol T0. Transaction failed.
EXCEPTION of type 'RuntimeError' occurred with message: '6881: Functions in CLA not supported - Logical channel not supported'
To enable full traceback, run the following command: 'set debug true'
</pre></p>
<a name="simtrace2-cardem-pcsc"></a>
<h2 >simtrace2-cardem-pcsc<a href="#simtrace2-cardem-pcsc" class="wiki-anchor">¶</a></h2>
<pre>
=> DATA: flags=2, 6f 3a : SW=0x6123, len_rx=0
-> 01 06 00 00 00 00 13 00 01 00 00 00 05 00 00 c0 00 00 23
=> DATA: flags=1, 00 c0 00 00 23 : SW=0x9000, len_rx=35
-> 01 06 00 00 00 00 13 00 01 00 00 00 05 00 00 b2 9d 04 22
=> DATA: flags=1, 00 b2 9d 04 22 : SW=0x9000, len_rx=34
-> 01 06 00 00 00 00 13 00 01 00 00 00 05 00 00 a4 00 04 02
=> DATA: flags=1, 00 a4 00 04 02 : -> 01 06 00 00 00 00 10 00 02 00 00 00 02 00 6f 3a
=> DATA: flags=2, 6f 3a : SW=0x6123, len_rx=0
-> 01 06 00 00 00 00 13 00 01 00 00 00 05 00 00 c0 00 00 23
=> DATA: flags=1, 00 c0 00 00 23 : SW=0x9000, len_rx=35
-> 01 06 00 00 00 00 13 00 01 00 00 00 05 00 00 b2 9e 04 22
=> DATA: flags=1, 00 b2 9e 04 22 : SW=0x9000, len_rx=34
-> 01 06 00 00 00 00 13 00 01 00 00 00 05 00 00 a4 00 04 02
=> DATA: flags=1, 00 a4 00 04 02 : -> 01 06 00 00 00 00 10 00 02 00 00 00 02 00 6f 3a
=> DATA: flags=2, 6f 3a : SW=0x6123, len_rx=0
-> 01 06 00 00 00 00 13 00 01 00 00 00 05 00 00 c0 00 00 23
=> DATA: flags=1, 00 c0 00 00 23 : SW=0x9000, len_rx=35
-> 01 06 00 00 00 00 13 00 01 00 00 00 05 00 00 b2 9f 04 22
=> DATA: flags=1, 00 b2 9f 04 22 : SW=0x9000, len_rx=34
-> 01 06 00 00 00 00 13 00 01 00 00 00 05 00 00 a4 00 04 02
=> DATA: flags=1, 00 a4 00 04 02 : -> 01 06 00 00 00 00 10 00 02 00 00 00 02 00 6f 3a
=> DATA: flags=2, 6f 3a : SW=0x6123, len_rx=0
-> 01 06 00 00 00 00 13 00 01 00 00 00 05 00 00 c0 00 00 23
=> DATA: flags=1, 00 c0 00 00 23 : SW=0x9000, len_rx=35
-> 01 06 00 00 00 00 13 00 01 00 00 00 05 00 00 b2 a0 04 22
=> DATA: flags=1, 00 b2 a0 04 22 : SW=0x9000, len_rx=34
-> 01 06 00 00 00 00 13 00 01 00 00 00 05 00 00 a4 00 04 02
=> DATA: flags=1, 00 a4 00 04 02 : -> 01 06 00 00 00 00 10 00 02 00 00 00 02 00 6f 3a
=> DATA: flags=2, 6f 3a : SW=0x6123, len_rx=0
-> 01 06 00 00 00 00 13 00 01 00 00 00 05 00 00 c0 00 00 23
=> DATA: flags=1, 00 c0 00 00 23 : SW=0x9000, len_rx=35
-> 01 06 00 00 00 00 13 00 01 00 00 00 05 00 00 b2 a1 04 22
=> DATA: flags=1, 00 b2 a1 04 22 : SW=0x9000, len_rx=34
-> 01 06 00 00 00 00 13 00 01 00 00 00 05 00 00 a4 00 04 02
=> DATA: flags=1, 00 a4 00 04 02 : -> 01 06 00 00 00 00 10 00 02 00 00 00 02 00 6f 3a
=> DATA: flags=2, 6f 3a : SW=0x6123, len_rx=0
-> 01 06 00 00 00 00 13 00 01 00 00 00 05 00 00 c0 00 00 60
=> DATA: flags=1, 00 c0 00 00 60 : SW=0x6c23, len_rx=0
-> 01 06 00 00 00 00 13 00 01 00 00 00 05 00 02 00 a4 00 04
<0000> apdu_dispatch.c:112 Unknown APDU case 0
=> DATA: flags=1, 02 00 a4 00 04 : SW=0x6881, len_rx=0
</pre>
<p>it also agrees that this last APDU is somehow wrong and cannot determine the APDU case.</p>
<a name="USB-communication"></a>
<h2 >USB communication<a href="#USB-communication" class="wiki-anchor">¶</a></h2>
<p>last message from SIMtrace to host is "RX DATA" with header flag set and 0200a40004. The card still responds with SW 6881 to that, as obviously the APDU header is invalid.</p>
<p><img src="https://osmocom.org/attachments/download/4852/wireshark.png" alt="" /></p> Core testing infrastructure - Bug #5301 (Stalled): Run TTCN3 docker tests with sanitizer enabledhttps://osmocom.org/issues/53012021-11-10T10:49:12Zdaniel
<p>After updating libosmocore I noticed that the TTCN3 GbProxy tests start to fail with an ASan issue when run locally.</p>
<p>I think at least for the TTCN3 tests on master we should enable <code>*San</code> to catch hidden bugs early. Unfortunately this has a large impact on how the <code>osmo-*-master</code> docker images are built if we want to enable it for the libraries as well - currently we install the nightly packages and build the target from master.</p>
<p>Instead we could build an image that builds all the libraries from master (with sanitizer enabled) and installs those and then use that as base for osmo-*-master.</p>
<p>Not sure what the downsides are, any ideas?</p> OsmoBTS - Bug #5242 (Stalled): A-bis/RSL: CRCX ACK indicates '0.0.0.0' as the local/bind addresshttps://osmocom.org/issues/52422021-09-30T09:25:47Zfixeria
<p>Currently both TC_speech_rtp_tchf and TC_speech_rtp_tchh fail, because CRCX ACK from osmo-bts indicates '0.0.0.0' as the local/bind address. The local/bind address of osmo-bts is needed in order to know where to send RTP packets for the RTP_Emulation component, and of course '0.0.0.0' cannot be used as the remote address for send(). See the attached PCAP file.</p> OsmoPCU - Bug #4947 (Stalled): osmo-pcu: Handling for Pkt Resource Req using Global TFI not imple...https://osmocom.org/issues/49472021-01-14T10:42:00Zpespin
<p>Related function (pdch.cpp):<br /><pre>
void gprs_rlcmac_pdch::rcv_resource_request(Packet_Resource_Request_t *request, uint32_t fn, struct pcu_l1_meas *meas)
</pre></p>
<p>In there, osmo-pcu correctly handles Pkt resource Request if the MS identifies using TLLI, but it does not if MS used Global TFI (for instance if the MS has already a Downlink TBF established).</p>
<p>There exists already a log ERROR to warn about it not being implemented, I just run through it on my local setup a few seconds after turning on my phone:<br /><pre>
20210114113407714 DL1IF pcu_l1_if.cpp:459 RACH request received: sapi=1 qta=-1, ra=0x75, fn=1169311, cur_fn=1169315, is_11bit=0 <--- first MS message after pcu started
20210114113408011 DTBF tbf_ul.cpp:107 Allocating UL TBF: MS_CLASS=12/12
20210114113408011 DTBF tbf.cpp:357 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=NULL EGPRS) Setting Control TS 6
20210114113408011 DTBF tbf.cpp:762 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=NULL EGPRS) Allocated: trx = 0, ul_slots = 40, dl_slots = 00
20210114113408011 DTBFUL tbf_ul.cpp:766 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=NULL EGPRS) setting EGPRS UL window size to 64, base(64) slots(1) ws_pdch(0)
20210114113408028 DTBF tbf.cpp:1028 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=ASSIGN EGPRS) start Packet Uplink Assignment (PACCH)
20210114113408029 DTBFDL tbf.cpp:603 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=ASSIGN EGPRS) Scheduled UL Assignment polling on PACCH (FN=1169402, TS=7)
20210114113408153 DTBF tbf.cpp:360 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=FLOW EGPRS) Changing Control TS 7 -> 6
20210114113408275 DTBF tbf_dl.cpp:133 Allocating DL TBF: MS_CLASS=12/12
20210114113408276 DTBF tbf.cpp:357 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=DL STATE=NULL EGPRS) Setting Control TS 6
20210114113408276 DTBF tbf.cpp:762 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=DL STATE=NULL EGPRS) Allocated: trx = 0, ul_slots = 40, dl_slots = e0
20210114113408276 DTBFDL tbf_dl.cpp:1496 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=DL STATE=NULL EGPRS) setting EGPRS DL window size to 64, base(64) slots(3) ws_pdch(0)
20210114113408276 DTBF tbf_dl.cpp:616 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=DL STATE=ASSIGN EGPRS) set ass. type PACCH [prev CCCH:0, PACCH:0]
20210114113408286 DTBF tbf.cpp:924 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=DL STATE=ASSIGN EGPRS) start Packet Downlink Assignment (PACCH)
20210114113408287 DTBFDL tbf.cpp:609 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=FINISHED EGPRS) Scheduled DL Assignment polling on PACCH (FN=1169458, TS=6)
20210114113408449 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1169493, TS=6
20210114113408550 DTBF tbf.cpp:303 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=FINISHED EGPRS) free
20210114113408587 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1169523, TS=6
20210114113408711 DTBF tbf_ul.cpp:107 Allocating UL TBF: MS_CLASS=12/12
20210114113408711 DTBF tbf.cpp:357 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=NULL EGPRS) Setting Control TS 6
20210114113408711 DTBF tbf.cpp:762 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=NULL EGPRS) Allocated: trx = 0, ul_slots = 40, dl_slots = 00
20210114113408712 DTBFUL tbf_ul.cpp:766 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=NULL EGPRS) setting EGPRS UL window size to 64, base(64) slots(1) ws_pdch(0)
20210114113408725 DTBF tbf.cpp:1028 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=ASSIGN EGPRS) start Packet Uplink Assignment (PACCH)
20210114113408726 DTBFDL tbf.cpp:603 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=DL STATE=FLOW EGPRS) Scheduled UL Assignment polling on PACCH (FN=1169553, TS=6)
20210114113408868 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1169584, TS=6
20210114113409007 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1169614, TS=6
20210114113409053 DTBF tbf.cpp:303 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=FINISHED EGPRS) free
20210114113409131 DTBF tbf_ul.cpp:107 Allocating UL TBF: MS_CLASS=12/12
20210114113409131 DTBF tbf.cpp:357 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=NULL EGPRS) Setting Control TS 6
20210114113409131 DTBF tbf.cpp:762 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=NULL EGPRS) Allocated: trx = 0, ul_slots = 40, dl_slots = 00
20210114113409132 DTBFUL tbf_ul.cpp:766 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=NULL EGPRS) setting EGPRS UL window size to 64, base(64) slots(1) ws_pdch(0)
20210114113409145 DTBF tbf.cpp:1028 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=ASSIGN EGPRS) start Packet Uplink Assignment (PACCH)
20210114113409146 DTBFDL tbf.cpp:603 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=DL STATE=FLOW EGPRS) Scheduled UL Assignment polling on PACCH (FN=1169644, TS=6)
20210114113409288 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1169675, TS=6
20210114113409427 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1169705, TS=6
20210114113409473 DTBF tbf.cpp:303 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=FINISHED EGPRS) free
20210114113409551 DTBF tbf_ul.cpp:107 Allocating UL TBF: MS_CLASS=12/12
20210114113409552 DTBF tbf.cpp:357 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=NULL EGPRS) Setting Control TS 6
20210114113409552 DTBF tbf.cpp:762 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=NULL EGPRS) Allocated: trx = 0, ul_slots = 40, dl_slots = 00
20210114113409552 DTBFUL tbf_ul.cpp:766 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=NULL EGPRS) setting EGPRS UL window size to 64, base(64) slots(1) ws_pdch(0)
20210114113409565 DTBF tbf.cpp:1028 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=ASSIGN EGPRS) start Packet Uplink Assignment (PACCH)
20210114113409566 DTBFDL tbf.cpp:603 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=DL STATE=FLOW EGPRS) Scheduled UL Assignment polling on PACCH (FN=1169735, TS=6)
20210114113409708 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1169766, TS=6
20210114113409847 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1169796, TS=6
20210114113409893 DTBF tbf.cpp:303 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=FINISHED EGPRS) free
20210114113409971 DTBF tbf_ul.cpp:107 Allocating UL TBF: MS_CLASS=12/12
20210114113409972 DTBF tbf.cpp:357 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=NULL EGPRS) Setting Control TS 6
20210114113409972 DTBF tbf.cpp:762 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=NULL EGPRS) Allocated: trx = 0, ul_slots = 40, dl_slots = 00
20210114113409972 DTBFUL tbf_ul.cpp:766 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=NULL EGPRS) setting EGPRS UL window size to 64, base(64) slots(1) ws_pdch(0)
20210114113409985 DTBF tbf.cpp:1028 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=UL STATE=ASSIGN EGPRS) start Packet Uplink Assignment (PACCH)
20210114113409986 DTBFDL tbf.cpp:603 TBF(TFI=0 TLLI=0xb01b4cd5 DIR=DL STATE=FLOW EGPRS) Scheduled UL Assignment polling on PACCH (FN=1169826, TS=6)
20210114113410128 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1169857, TS=6
20210114113410313 DTBF tbf.cpp:303 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=UL STATE=FINISHED EGPRS) free
20210114113410405 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1169917, TS=6
20210114113410548 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1169948, TS=6
20210114113410687 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1169978, TS=6
20210114113410825 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1170008, TS=6
20210114113410968 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1170039, TS=6
20210114113411107 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1170069, TS=6
20210114113411245 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1170099, TS=6
20210114113411388 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1170130, TS=6
20210114113411526 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1170160, TS=6
20210114113411665 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1170190, TS=6
20210114113411808 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1170221, TS=6
20210114113411947 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1170251, TS=6
20210114113412085 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1170281, TS=6
20210114113412228 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FINISHED EGPRS) Scheduled Ack/Nack polling on FN=1170312, TS=6
20210114113413953 DTBF tbf.cpp:466 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=WAIT RELEASE EGPRS) T3193 timeout expired, freeing TBF
20210114113413953 DTBF tbf.cpp:473 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=WAIT RELEASE EGPRS) T3193 timeout expired, freeing TBF
20210114113413953 DTBF tbf.cpp:303 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=RELEASING EGPRS) free
20210114113414240 DL1IF pcu_l1_if.cpp:459 RACH request received: sapi=1 qta=-1, ra=0x70, fn=1170725, cur_fn=1170728, is_11bit=0
20210114113414550 DTBF tbf_ul.cpp:107 Allocating UL TBF: MS_CLASS=12/12
20210114113414551 DTBF tbf.cpp:357 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=UL STATE=NULL EGPRS) Setting Control TS 6
20210114113414551 DTBF tbf.cpp:762 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=UL STATE=NULL EGPRS) Allocated: trx = 0, ul_slots = 40, dl_slots = 00
20210114113414551 DTBFUL tbf_ul.cpp:766 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=UL STATE=NULL EGPRS) setting EGPRS UL window size to 64, base(64) slots(1) ws_pdch(0)
20210114113414563 DTBF tbf.cpp:1028 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=UL STATE=ASSIGN EGPRS) start Packet Uplink Assignment (PACCH)
20210114113414564 DTBFDL tbf.cpp:603 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=UL STATE=ASSIGN EGPRS) Scheduled UL Assignment polling on PACCH (FN=1170819, TS=7)
20210114113414693 DTBF tbf.cpp:360 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=UL STATE=FLOW EGPRS) Changing Control TS 7 -> 6
20210114113414815 DTBF tbf_dl.cpp:133 Allocating DL TBF: MS_CLASS=12/12
20210114113414815 DTBF tbf.cpp:357 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=NULL EGPRS) Setting Control TS 6
20210114113414815 DTBF tbf.cpp:762 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=NULL EGPRS) Allocated: trx = 0, ul_slots = 40, dl_slots = e0
20210114113414815 DTBFDL tbf_dl.cpp:1496 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=NULL EGPRS) setting EGPRS DL window size to 64, base(64) slots(3) ws_pdch(0)
20210114113414815 DTBF tbf_dl.cpp:616 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=ASSIGN EGPRS) set ass. type PACCH [prev CCCH:0, PACCH:0]
20210114113414822 DTBF tbf.cpp:924 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=ASSIGN EGPRS) start Packet Downlink Assignment (PACCH)
20210114113414823 DTBFDL tbf.cpp:609 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=UL STATE=FINISHED EGPRS) Scheduled DL Assignment polling on PACCH (FN=1170875, TS=6)
20210114113414984 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1170910, TS=6
20210114113415089 DTBF tbf.cpp:303 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=UL STATE=FINISHED EGPRS) free
20210114113415122 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1170940, TS=6
20210114113415251 DTBF tbf_ul.cpp:107 Allocating UL TBF: MS_CLASS=12/12
20210114113415251 DTBF tbf.cpp:357 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=UL STATE=NULL EGPRS) Setting Control TS 6
20210114113415251 DTBF tbf.cpp:762 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=UL STATE=NULL EGPRS) Allocated: trx = 0, ul_slots = 40, dl_slots = 00
20210114113415251 DTBFUL tbf_ul.cpp:766 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=UL STATE=NULL EGPRS) setting EGPRS UL window size to 64, base(64) slots(1) ws_pdch(0)
20210114113415260 DTBF tbf.cpp:1028 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=UL STATE=ASSIGN EGPRS) start Packet Uplink Assignment (PACCH)
20210114113415261 DTBFDL tbf.cpp:603 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FLOW EGPRS) Scheduled UL Assignment polling on PACCH (FN=1170970, TS=6)
20210114113415408 DTBFDL tbf_dl.cpp:998 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=DL STATE=FLOW EGPRS) Scheduled Ack/Nack polling on FN=1171001, TS=6
20210114113415473 DTBFUL pdch.cpp:661 TBF(TFI=0 TLLI=0xe8bfe3d8 DIR=UL STATE=FLOW EGPRS) RX: [PCU <- BTS] FIXME: Packet resource request <------------------- !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
</pre></p> osmo-e1d - Bug #4916 (Stalled): USB unplug / replug renders e1d unusablehttps://osmocom.org/issues/49162020-12-18T10:28:45Zlaforge
right now the behavior on USB unplug (or - god forbid - a firmware crash) is not very user friendly:
<ul>
<li>e1d keeps running</li>
<li>e1d does not re-open the device when it comes back</li>
</ul>
IMHO, we have the following options
<ol>
<li>fail fast - simply exit when the device is lost, assume systemd or some other management instance will keep respawning us until the device is back
<ul>
<li>but what about client programs like osmo-bsc / osmo-mgw ?</li>
</ul>
</li>
<li>implement re-opening of a single icE1usb device, knowing our blocking control transfers would corrupt any other ongoing communication
<ul>
<li>is it worth the effort, assuming this is only an interim solution</li>
</ul>
</li>
<li>go for a full-blown hot-plug capable architecture lined out in <a class="issue tracker-2 status-1 priority-1 priority-lowest" title="Feature: consider a one-thread-per-line architecture (New)" href="https://osmocom.org/issues/4915">#4915</a>
<ul>
<li>will probably take significant effort</li>
</ul></li>
</ol>
<p>I think right now we mostly have to worry about situations with a single icE1usb, so I'm tempted to go for the fail-fast approach, assuming osmo-bsc/osmo-mgw recover in some way.</p> OsmoPCU - Bug #4879 (Stalled): endless pdch.cpp:809 Got CS-N RLC block: R=0, SI=0, TFI=0, CPS=0, ...https://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> OsmoBSC - Bug #4832 (Stalled): osmo-bsc hard-releases lchan if no MSC is foundhttps://osmocom.org/issues/48322020-10-25T20:52:07Zlaforge
<p>As described in <a class="issue tracker-1 status-7 priority-3 priority-high3" title="Bug: OsmocomBB Rx bit errors in dedicated mode (Stalled)" href="https://osmocom.org/issues/4829">#4829</a>:</p>
<p>So.... the problem is something else altogether, or at least a large part of the problem.</p>
For some reason, osmo-bsc these days <strong>immediately hard-releases the lchan</strong> if there is no MSC. There is no signaling sent back to the MS about this:
<ul>
<li>no spoofing of MM/CM (LU REJECT, CM SERV REJECT, ...) which is still understandable, as it's a layering violation and those messages normally originat e at the MSC</li>
<li><strong>No RR CHANNEL RELEASE is sent to the MS</strong>. That is a big fat bug.</li>
</ul>
<p>Instead, we simply immedaitely close the lchan on the BTS side. This of course means that from that point onwards there re only bit-errors in downlink in the UE.</p>
<pre>
DRSL INFO <0003> ../../../git/src/osmo-bsc/abis_rsl.c:1453 (bts=0) CHAN RQD: reason: Location updating (ra=0x0f, neci=0x01, chreq_reason=0x03)
DCHAN INFO <000f> ../../../git/src/osmo-bsc/lchan_select.c:247 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{UNUSED}: (type=SDCCH) Selected
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/abis_rsl.c:1657 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{UNUSED}: (type=SDCCH) MS: Channel Request: reason=LOCATION_UPDATE ra=0x0f ta=0
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:329 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{UNUSED}: Received Event LCHAN_EV_ACTIVATE
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:548 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{UNUSED}: state_chg to WAIT_TS_READY
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/gsm_data.c:861 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_TS_READY}: (type=SDCCH) MS Power level update requested: 15 dBm
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/gsm_data.c:893 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_TS_READY}: (type=SDCCH) MS Power level update (power class 0): 0 -> 7
DCHAN INFO <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:626 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_TS_READY}: (type=SDCCH) Activation requested: FOR_MS_CHANNEL_REQUEST voice=no MGW-ci=none type=SDCCH tch-mode=SIGNALLING encr-alg=A5/0 ck=none
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/timeslot_fsm.c:106 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_TS_READY}: Received Event LCHAN_EV_TS_READY
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:644 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_TS_READY}: state_chg to WAIT_ACTIV_ACK
DRSL DEBUG <0003> ../../../git/src/osmo-bsc/abis_rsl.c:476 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4,state=IN_USE) Tx RSL Channel Activate with act_type=INITIAL
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/abis_rsl.c:1152 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_ACTIV_ACK}: (type=SDCCH) Rx CHAN_ACTIV_ACK
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/abis_rsl.c:1164 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_ACTIV_ACK}: Received Event LCHAN_EV_RSL_CHAN_ACTIV_ACK
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:772 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_ACTIV_ACK}: (type=SDCCH) Tx RR Immediate Assignment
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:822 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_ACTIV_ACK}: state_chg to WAIT_RLL_RTP_ESTABLISH
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/abis_rsl.c:1899 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_RLL_RTP_ESTABLISH}: (type=SDCCH) SAPI=0 ESTABLISH INDICATION
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/abis_rsl.c:1932 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_RLL_RTP_ESTABLISH}: Received Event LCHAN_EV_RLL_ESTABLISH_IND
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:850 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_RLL_RTP_ESTABLISH}: state_chg to ESTABLISHED
DRSL ERROR <0003> ../../../git/src/osmo-bsc/gsm_08_08.c:483 MM GSM48_MT_MM_LOC_UPD_REQUEST: IMSI-001010000000001: No suitable MSC for this Complete Layer 3 request found
DRSL DEBUG <0003> ../../../git/src/osmo-bsc/abis_rsl.c:644 (bts=0,trx=0,ts=0,ss=0) DEACTivate SACCH CMD
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:1595 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{ESTABLISHED}: state_chg to WAIT_RF_RELEASE_ACK
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/bsc_subscr_conn_fsm.c:778 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_RF_RELEASE_ACK}: conn SUBSCR_CONN(msc4294967295-conn4294967295_subscr-IMSI-001010000000001)[0x28adc0] detaches lchan (primary lchan)
DMSC ERROR <0007> ../../../git/src/osmo-bsc/bsc_subscr_conn_fsm.c:153 SUBSCR_CONN(msc4294967295-conn4294967295_subscr-IMSI-001010000000001)[0x28adc0]{INIT}: Unable to deliver BSSMAP Clear Request message, no MSC for this conn
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:1644 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_RF_RELEASE_ACK}: lchan detaches from conn SUBSCR_CONN(msc4294967295-conn4294967295_subscr-IMSI-001010000000001)[0x28adc0]
DLINP ERROR <0017> ../../git/src/input/ipaccess.c:412 Bad signalling message, sign_link returned error: No such file or directory.
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/abis_rsl.c:1152 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_RF_RELEASE_ACK}: (type=SDCCH) Rx RF_CHAN_REL_ACK
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/abis_rsl.c:1184 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_RF_RELEASE_ACK}: Received Event LCHAN_EV_RSL_RF_CHAN_REL_ACK
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:1206 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_RF_RELEASE_ACK}: state_chg to WAIT_AFTER_ERROR
DLSS7 ERROR <0021> ../../git/src/m3ua.c:507 XUA_AS(as-clnt-A-0-m3ua)[0x253d70]{AS_DOWN}: Event AS-TRANSFER.req not permitted
DCHAN DEBUG <000f> ../../git/src/fsm.c:322 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_AFTER_ERROR}: Timeout of X3111
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:1550 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_AFTER_ERROR}: state_chg to UNUSED
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:382 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{UNUSED}: (type=SDCCH) Clearing lchan state
</pre>
<p>We should at the very minimum send a proper RR CHANNEL RELEASE to the MS, so it knows the channel is closed. That's the least we can do. However, it also means that the MS will likely start re-trying again and again. After all, it did not receive any reject with a cause value that would tell it to back off.</p>
<p>So I think we actually should either simply not hard-fast-close but let things run into some timeout (send SCCP connect request but then no response received?), or do the effort of spoofing a LU REJECT / CM SERVICE REJECt with a suitable Reject Cause IE ("Network Failure" or "Service option temporarily out of order" look good to me).</p>
<p>Another oddity about this problem is that it only shows if the MSC is absent when the BSC starts up. If the BSC has once seen the MSC, then it considers it 'eligible'. Even if the MSC then is gone at a later point, it will not go back to this hard-fast-clear behavior (at least not quickly?).</p> OsmoBTS - Bug #4801 (Stalled): BTS_Tests.TC_tch_sign_l2_fill_frame_dtxd failshttps://osmocom.org/issues/48012020-10-11T19:52:01Zlaforge
<p>The tests fails with the sttement</p>
<pre>
TC_tch_sign_l2_fill_frame_dtxd(6)@nataraja: received only 2+0 (SACCH+other) out of 3 expected fill frames
MTC@nataraja: Test case TC_tch_sign_l2_fill_frame_dtxd finished. Verdict: fail reason: "BTS_Tests.ttcn:6675 : Not enough fill frames received"
</pre>
<p>So it seems like the SACCH in downlink is received, but the fill frames that should be sent by the related code in osmo-bts (<a class="external" href="https://gerrit.osmocom.org/c/osmo-bts/+/10415">https://gerrit.osmocom.org/c/osmo-bts/+/10415</a>) are either not sent, or somehow lost, or not detected by the test case.</p> OsmoPCU - Bug #4452 (Stalled): manual testing of osmo-pcuhttps://osmocom.org/issues/44522020-03-10T15:46:02Zroh
<p>these are manual testruns with osmo-pcu and osmo-bts-sysmo from -nightly and the cni running on debian on an apu.</p>
<p>attached are the configs for the sysmobts (osmo-pcu and osmo-bts-sysmo) as well as the remaining cni (on debian9 from -nightly)</p>
<p>the pcap files are generated by dumping the complete interface on the bsc. in addition to that the gsmtap for -bts and -pcu sends its debug there.<br />the pcap file(s) are single runs: getting the phone from airplane mode - register - do a network request - airplane mode.</p> OsmoBTS - Bug #4023 (Stalled): Missing coverage of PCU interface in osmo-btshttps://osmocom.org/issues/40232019-05-24T20:19:52Zlaforge
<p>let's use this as a separate ticket from <a class="issue tracker-2 status-3 priority-2 priority-default closed" title="Feature: Extension of BTS_Tests.ttcn test coverage (Resolved)" href="https://osmocom.org/issues/3750">#3750</a> to provide a more verbose list of the tests related to the PCU interface</p> OsmocomBB SDR PHY - Bug #3459 (Stalled): apps/grgsm_trx: AssertionError: packe t_info.packet_coun...https://osmocom.org/issues/34592018-08-09T19:10:03Zfixeria
<p>Despite actual burst transmission works, I see the following messages repeated multiple times:</p>
<pre>
[i] Recv POWEROFF cmd
[i] Stopping transceiver...
[i] Setting TA value 0
[i] Recv ECHO cmd
[i] Recv SETSLOT cmd
[i] Configure timeslot filter to: drop all
[i] Recv MEASURE cmd
[i] Recv POWEROFF cmd
[i] Recv ECHO cmd
[i] Recv SETSLOT cmd
[i] Configure timeslot filter to: TS 0
[i] Recv POWERON CMD
[i] Starting transceiver...
thread[thread-per-block[15]: <block gr uhd usrp sink (8)>]: EnvironmentError: IOError: Radio ctrl (0) packet parse error - AssertionError: packe
t_info.packet_count == (seq_to_ack & 0xfff)
in uint64_t radio_ctrl_core_3000_impl::wait_for_ack(bool)
at /build/libuhd/src/uhd-3.11.1.0/host/lib/usrp/cores/radio_ctrl_core_3000.cpp:254
</pre>
<p>Observed within a Docker image wit the recent software:</p>
<ul>
<li>UHD_3.11.1.0-0-unknown</li>
<li>GNU Radio 3.7.11-6</li>
<li>GR-GSM TRX from fixeria/trx</li>
</ul>
<p>Could you please have a look?<br />Do you see this too?</p> OsmocomBB SDR PHY - Bug #3458 (Stalled): apps/grgsm_trx: [ERROR] [STREAMER] recv packet demuxer u...https://osmocom.org/issues/34582018-08-09T18:29:31Zfixeria
<p>Sometimes, while running the following output appears:</p>
<pre>
[i] Recv ECHO cmd
[i] Recv POWEROFF cmd
[i] Recv ECHO cmd
[i] Recv SETSLOT cmd
[i] Configure timeslot filter to: TS 0
[i] Recv RXTUNE cmd
[i] Recv TXTUNE cmd
[i] Recv POWERON CMD
[i] Starting transceiver...
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x0
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x0
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x0
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x0
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x0
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x0
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x0
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x0
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x0
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x0
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x0
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x4a000f
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xe0024
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x37ffe7
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x1b0005
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xff530020
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xcff6d
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x7ffc8
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xffbeff95
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x65000f
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xffb20072
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x16ffc9
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xfff5fff1
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xffc400bb
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xcffdd
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xffdcffcb
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xffb2fff5
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xffd5ffc4
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x38fff2
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xffcf0000
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xbb0069
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x12ffcc
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xffb6001f
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xffd7001e
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x14004c
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xffa6ffe8
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xa002a
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xff76003f
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xff96ffd3
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x130013
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xffd5ffe3
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x4001e
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xff8c0075
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xfff0000f
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xdffee
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xfff40011
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x1afff9
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xff9aff5d
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xff9afffa
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x7ffce
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xffcb0008
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xfff7ffdd
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x5a005e
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x38ffca
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x6ffa2
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x4ffcc
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xffba00ab
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xff420029
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x1effe2
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x70067
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x1a001e
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x1a0016
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xb00a5
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xffbe0008
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xffe6001a
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xffcfffc3
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0x130003
[ERROR] [STREAMER] recv packet demuxer unexpected sid 0xffceff44
</pre> OsmocomBB SDR PHY - Bug #3425 (Stalled): Receiver: missing AGC (Automatic Gain Control)https://osmocom.org/issues/34252018-07-26T20:25:52Zfixeria
<p>When the signal becomes too strong, we need to decrease the gain to avoid saturation.<br />When the signal becomes less powerful, we need to increase the gain...</p> OsmocomBB SDR PHY - Bug #3422 (Stalled): Receiver: sample / burst buffering problemhttps://osmocom.org/issues/34222018-07-26T20:08:47Zfixeria
<p>The problem appears when one stops the flow-graph, changes some parameters (e.g. freq.) and starts it again.<br />As soon as the flow-graph is started, Receiver block will still output some bursts from the past for some time.</p>
<p>Please note that <strong>I just assume</strong> that this is a problem of Receiver block.<br />It might be also a problem of any other block(s), such as 'TRX Interface'.</p> SIMtrace 2 - Bug #3379 (Stalled): documentation on how to use SIMtrace2https://osmocom.org/issues/33792018-07-04T16:10:36Zlaforge
<p>the wiki in the SIMtrace2 redmine project currently only documents flashing, but there should of course be good information on how to use the host tools in order to run the complete system.</p> OsmoTRX - Bug #3342 (Stalled): osmo-trx-lms: low tx output power levelhttps://osmocom.org/issues/33422018-06-13T16:56:06Zlaforge
<p>According to <a class="external" href="https://discourse.myriadrf.org/t/limesdr-s-maximum-transmitting-power-at-different-frequencies/1649">https://discourse.myriadrf.org/t/limesdr-s-maximum-transmitting-power-at-different-frequencies/1649</a> I would expect something like 3-5dBm maximum output power at 1.8 GHz.</p>
<p>Hoewever, when running at ARFCN 871, and even when manually patching <code>LMS_SetNormalizedGain(m_lms_dev, LMS_CH_TX, chan, 1.0);</code> into the osmo-trx-lms source code, I'm not seeing more than -3.8 dB coming out of the TX1_1 port of the device. Where does that 6..8 dB difference come from?</p>