OpenBSC April 2019

openbsc@lists.osmocom.org

21 participants
22 discussions

Hard-dropping a PDP Context (SGSN)
by Mykola Shchetinin 23 Apr '19

23 Apr '19

Dear Osmocom community, A question about this part of code - function sgsn_ggsn_ctx_drop_pdp: http://git.osmocom.org/osmo-sgsn/tree/src/gprs/gprs_sgsn.c#n720 The second branch of the condition (hard-dropping) is called even when the phone is registered, and hence no Deactivate PDP Context Request is sent to the phone. Due to that, the phone doesn't know that the PDP Context was deleted on the network side and keeps acting as if it is still active -> the PS isn't working when this happens. Any suggestions/thoughts on how this can be fixed? Thanks Kind regards, Mykola

2 1

LimeNet Micro for BTS
by Rafael Diniz 15 Apr '19

15 Apr '19

Hi all, Have anyone tried Osmo GSM stack (including the trx) with the LimeNet Micro with the Pi compute module? My question is if it is stable enough for any real deployment or just another toy for the lab. With the USB3 LimeSDR, after a few hours I _always_ get a broken trx, with lots of failure messages... Thanks, Rafael Diniz Rhizomatica

5 7

gsmtap design/extensions?
by Johannes Berg 15 Apr '19

15 Apr '19

Hi, As I'm looking into adding a generic cell modem framework to the linux kernel (to create session netdevs etc.), I started looking for a metadata encapsulation, a la Radiotap (I'm a wifi guy :-) ). So obviously, I found gsmtap, but for my use case it doesn't really address most of the interesting data, and it got me wondering. So a few questions, if I may: 1) Why the design with encapsulating it in UDP? Radiotap is just a raw header without IP etc. in front, and you use it with tcpdump, wireshark or similar tools on the local system. What's the value in having something "network transparent"? 2) The format of gsmtap doesn't seem very extensible, but I guess a new version could be made that has a TLV-based format or so. I'd have argued that a new version isn't even needed, but the length field is only 8 bits right now which seems too short. (speaking of versions - the docs say "version, set to 0x01 currently" but "#define GSMTAP_VERSION 0x02") 3) Does the packet data follow the gsmtap header? It's not really clear to me based on reading the wireshark code. In particular, the data I'm thinking of is higher-level things, like the session ID for a frame when it's going through the kernel, or perhaps a flow label on RX, etc. Also, vendor-specific data would be useful, e.g. to encapsulate the device-specific headers like QMI, where such metadata is encapsulated in a vendor- or device-specific way, which you'd want to see for debugging certain things, but for other things the generic "session ID" type information - encoded in a vendor-agnostic way - would be better to show in wireshark. Since it doesn't seem possible to use gsmtap in the current version, would it make sense to define a new gsmtap that (say) has version 3 or something, followed by an overall length and TLVs? I do note that this wouldn't be compatible with the current wireshark code as it doesn't check the version, just shows it... Or would it make more sense to define a new ARPHDR_WWANTAP like ARPHDR_IEEE80211_RADIOTAP and just use that instead of encapsulating in IP/UDP, and then have a completely new (extensible) protocol inside of that? I'm not really sure I see the point of UDP encapsulation anyway. Thanks, johannes

6 22

sccp conn_id weirdness
by Neels Hofmeyr 12 Apr '19

12 Apr '19

I noticed some odd behavior in our SCCP stack, let me outline. Should this become a new issue? Because the osmo_scu_prim conn_id patches aren't merged yet, I put a temporary shim in place like we have in osmo-bsc to figure out new outgoing conn_ids. With this shim I noticed that some conn_ids work better than others: struct ran_conn *ran_conn_create_outgoing(struct ran_peer *ran_peer) { /* FIXME use method being developed in gerrit id Ifd55c6b7ed2558ff072042079cf45f5068a971de */ static uint32_t next_outgoing_conn_id = 0x80000000; uint32_t conn_id = 0; int attempts = 1000; bool already_used = true; while (attempts--) { struct ran_conn *conn; conn_id = next_outgoing_conn_id; next_outgoing_conn_id++; already_used = false; llist_for_each_entry(conn, &ran_peer->sri->ran_conns, entry) { if (conn->sccp_conn_id == conn_id) { already_used = true; break; } } if (!already_used) break; } if (already_used) return NULL; LOG_RAN_PEER(ran_peer, LOGL_DEBUG, "Outgoing conn id: %u\n", conn_id); return ran_conn_create_incoming(ran_peer, conn_id); } The weird thing is that the conn_id of 0x80000000 does *NOT* work and gets me a log line of: DLSCCP NOTICE Cannot find connection for local reference 0 (sccp_scoc.c:1636) where the MSC should be sending out the initial N-CONNECT to osmo-bsc. However, if I set the initial value to: next_outgoing_conn_id = 2342; then everything works out fine. I am at a loss to understand why this would happen, and currently don't have the cycles left to investigate. Maybe someone else wants to investigate why this happens... Logging for the failing case with 0x80000000: (the source file numbers might be a bit off current master) 20190412033755322 DBSSAP DEBUG ran_peer(GERAN-A:RI-SSN_PC:PC-1-23-4:SSN-BSSAP)[0x61200000aea0]{READY}: Outgoing conn id: 2147483648 (ran_conn.c:81) [...] 20190412033755327 DBSSAP DEBUG msc_t(IMSI-901700000014705:GERAN-A-2147483648:NONE)[0x61200001b220]{WAIT_HO_REQUEST_ACK}: NAS encode: BSSMAP: HANDOVER_REQUEST (nas_a.c:1159) 20190412033755328 DRR DEBUG ran_peer(GERAN-A:RI-SSN_PC:PC-1-23-4:SSN-BSSAP)[0x61200000aea0]{READY}: Received Event RAN_PEER_EV_MSG_DOWN_CO_INITIAL (ran_conn.c:119) 20190412033755328 DLSCCP DEBUG Received SCCP User Primitive (N-CONNECT.request) (sccp_scoc.c:1712) 20190412033755328 DLSCCP DEBUG SCCP-SCOC(2147483648)[0x6120000201a0]{IDLE}: Allocated (fsm.c:423) 20190412033755328 DLSCCP DEBUG SCCP-SCOC(2147483648)[0x6120000201a0]{IDLE}: Received Event N-CONNECT.req (sccp_scoc.c:1753) 20190412033755328 DLSS7 DEBUG sccp_scrc_rx_scoc_conn_msg: HDR=(CO:CORE,V=0,LEN=0), PART(T=Routing Context,L=4,D=00000000), PART(T=Protocol Class,L=4,D=00000002), PART(T=Source Reference,L=4,D=80000000), PART(T=Destination Address,L=20,D=0002000380020008000008bc80030008000000fe), PART(T=Sequence Control,L=4,D=00000000), PART(T=Source Address,L=20,D=0002000380020008000008b980030008000000fe), PART(T=Data,L=83,D=0051100b07010aa19181a5050a09004ad48954cb991d2912035058a605080062f224002a000005080009f1070046000104010c130a6014042f6500200240422c04080899100700001074507c06c0a80204a418) (sccp_scrc.c:398) 20190412033755328 DLSUA DEBUG sua_addr_parse_part(IEI=0x0103) (20) 00 02 00 03 80 02 00 08 00 00 08 bc 80 03 00 08 00 00 00 fe (sua.c:385) 20190412033755328 DLSUA DEBUG SUA IEI 0x0103 pos 4/20: subpart tag 0x8002, len 8 (sua.c:439) 20190412033755328 DLSUA DEBUG SUA IEI 0x0103 pos 12/20: subpart tag 0x8003, len 8 (sua.c:439) 20190412033755328 DLSUA DEBUG sua_addr_parse_part(IEI=0x0103) (20) 00 02 00 03 80 02 00 08 00 00 08 bc 80 03 00 08 00 00 00 fe (sua.c:385) 20190412033755328 DLSUA DEBUG SUA IEI 0x0103 pos 4/20: subpart tag 0x8002, len 8 (sua.c:439) 20190412033755328 DLSUA DEBUG SUA IEI 0x0103 pos 12/20: subpart tag 0x8003, len 8 (sua.c:439) 20190412033755328 DLSUA DEBUG sua_addr_parse_part(IEI=0x0102) (20) 00 02 00 03 80 02 00 08 00 00 08 b9 80 03 00 08 00 00 00 fe (sua.c:385) 20190412033755328 DLSUA DEBUG SUA IEI 0x0102 pos 4/20: subpart tag 0x8002, len 8 (sua.c:439) 20190412033755328 DLSUA DEBUG SUA IEI 0x0102 pos 12/20: subpart tag 0x8003, len 8 (sua.c:439) 20190412033755328 DLSS7 DEBUG m3ua_hmdc_rx_from_l2(): dpc=2236=1.23.4 not local, message is for routing (osmo_ss7_hmrt.c:278) 20190412033755328 DLSS7 DEBUG Found route for dpc=2236=1.23.4: pc=0=0.0.0 mask=0x0=0.0.0 via AS as-clnt-OsmoMSC-A-Iu proto=m3ua (osmo_ss7_hmrt.c:227) 20190412033755328 DLSS7 DEBUG rt->dest.as proto is M3UA for dpc=2236=1.23.4 (osmo_ss7_hmrt.c:233) 20190412033755328 DLSS7 DEBUG XUA_AS(as-clnt-OsmoMSC-A-Iu)[0x61200000a720]{AS_ACTIVE}: Received Event AS-TRANSFER.req (m3ua.c:507) 20190412033755329 DLSCCP DEBUG SCCP-SCOC(2147483648)[0x6120000201a0]{IDLE}: State change to CONN_PEND_OUT (no timeout) (sccp_scoc.c:829) 20190412033755329 DLMGCP DEBUG mgw-endpoint(IMSI-901700000014705:GERAN-A-2147483648:NONE)[0x61200001b6a0]{WAIT_MGW_RESPONSE}: rtpbridge/2@msc CI[0] RTP_TO_RAN CI=88A322A7: CRCX: done (rtpbridge/2@msc:192.168.2.4:42008) (mgcp_client_endpoint_fsm.c:651) 20190412033755329 DLMGCP DEBUG mgw-endpoint(IMSI-901700000014705:GERAN-A-2147483648:NONE)[0x61200001b6a0]{WAIT_MGW_RESPONSE}: rtpbridge/2@msc CI[1] RTP_TO_CN CI=55D5651B: CRCX: done (rtpbridge/2@msc:192.168.2.4:42010) (mgcp_client_endpoint_fsm.c:651) 20190412033755329 DLMGCP DEBUG mgw-endpoint(IMSI-901700000014705:GERAN-A-2147483648:NONE)[0x61200001b6a0]{WAIT_MGW_RESPONSE}: rtpbridge/2@msc CI in use: 2, waiting for response: 0 (mgcp_client_endpoint_fsm.c:669) 20190412033755329 DLMGCP DEBUG mgw-endpoint(IMSI-901700000014705:GERAN-A-2147483648:NONE)[0x61200001b6a0]{WAIT_MGW_RESPONSE}: State change to IN_USE (no timeout) (mgcp_client_endpoint_fsm.c:680) 20190412033755329 DLMGCP DEBUG mgw-endpoint(IMSI-901700000014705:GERAN-A-2147483648:NONE)[0x61200001b6a0]{IN_USE}: rtpbridge/2@msc CI[0] RTP_TO_RAN CI=88A322A7: CRCX: done (rtpbridge/2@msc:192.168.2.4:42008) (mgcp_client_endpoint_fsm.c:651) 20190412033755329 DLMGCP DEBUG mgw-endpoint(IMSI-901700000014705:GERAN-A-2147483648:NONE)[0x61200001b6a0]{IN_USE}: rtpbridge/2@msc CI[1] RTP_TO_CN CI=55D5651B: CRCX: done (rtpbridge/2@msc:192.168.2.4:42010) (mgcp_client_endpoint_fsm.c:651) 20190412033755329 DLINP DEBUG [ CONNECTED] osmo_stream_cli_fd_cb(): connected write (stream.c:300) 20190412033755329 DLINP DEBUG [ CONNECTED] osmo_stream_cli_write(): sending data (stream.c:225) 20190412033755329 DLINP DEBUG [ CONNECTED] osmo_stream_cli_fd_cb(): connected write (stream.c:300) 20190412033755329 DLINP DEBUG [ CONNECTED] osmo_stream_cli_write(): sending data (stream.c:225) 20190412033755332 DLINP DEBUG [ CONNECTED] osmo_stream_cli_fd_cb(): connected read (stream.c:296) 20190412033755332 DLINP DEBUG [ CONNECTED] osmo_stream_cli_read(): message received (stream.c:210) 20190412033755332 DLSS7 DEBUG asp-asp-clnt-OsmoMSC-A-Iu: xua_cli_read_cb(): sctp_recvmsg() returned 48 (flags=0x80) (osmo_ss7.c:1609) 20190412033755333 DLM3UA DEBUG asp-asp-clnt-OsmoMSC-A-Iu: Received M3UA Message (XFER:DATA) (m3ua.c:722) 20190412033755333 DLM3UA DEBUG asp-asp-clnt-OsmoMSC-A-Iu: m3ua_rx_xfer (m3ua.c:541) 20190412033755333 DLM3UA DEBUG asp-asp-clnt-OsmoMSC-A-Iu: m3ua_rx_xfer(): M3UA data header: opc=2236=1.23.4 dpc=2233=1.23.1 (m3ua.c:580) 20190412033755333 DLSS7 DEBUG m3ua_hmdc_rx_from_l2(): found dpc=2233=1.23.1 as local (osmo_ss7_hmrt.c:274) 20190412033755333 DLSUA DEBUG IEI 259: Parsed Addr: RI=2,PC=2236,SSN=254 (sccp2sua.c:333) 20190412033755333 DLSS7 DEBUG scrc_rx_mtp_xfer_ind_xua: HDR=(CO:COAK,V=0,LEN=0), PART(T=Protocol Class,L=4,D=00000002), PART(T=Destination Reference,L=4,D=00000000), PART(T=Source Reference,L=4,D=00000000), PART(T=Destination Address,L=20,D=0002000380020008000008bc80030008000000fe) (sccp_scrc.c:450) 20190412033755333 DLSCCP NOTICE Cannot find connection for local reference 0 (sccp_scoc.c:1636) 20190412033755333 DLSS7 DEBUG sccp_scrc_rx_scoc_conn_msg: HDR=(CO:COERR,V=0,LEN=0), PART(T=Routing Context,L=4,D=00000000), PART(T=Destination Reference,L=4,D=00000000), PART(T=Cause,L=4,D=00000500) (sccp_scrc.c:398) 20190412033755333 DLSS7 DEBUG m3ua_hmdc_rx_from_l2(): dpc=2236=1.23.4 not local, message is for routing (osmo_ss7_hmrt.c:278) 20190412033755333 DLSS7 DEBUG Found route for dpc=2236=1.23.4: pc=0=0.0.0 mask=0x0=0.0.0 via AS as-clnt-OsmoMSC-A-Iu proto=m3ua (osmo_ss7_hmrt.c:227) 20190412033755333 DLSS7 DEBUG rt->dest.as proto is M3UA for dpc=2236=1.23.4 (osmo_ss7_hmrt.c:233) 20190412033755333 DLSS7 DEBUG XUA_AS(as-clnt-OsmoMSC-A-Iu)[0x61200000a720]{AS_ACTIVE}: Received Event AS-TRANSFER.req (m3ua.c:507) 20190412033755333 DLINP DEBUG [ CONNECTED] osmo_stream_cli_fd_cb(): connected write (stream.c:300) 20190412033755333 DLINP DEBUG [ CONNECTED] osmo_stream_cli_write(): sending data (stream.c:225) 20190412033755334 DLINP DEBUG [ CONNECTED] osmo_stream_cli_fd_cb(): connected write (stream.c:300) 20190412033755334 DLINP DEBUG [ CONNECTED] osmo_stream_cli_write(): sending data (stream.c:225) 20190412033755337 DLINP DEBUG [ CONNECTED] osmo_stream_cli_fd_cb(): connected read (stream.c:296) 20190412033755337 DLINP DEBUG [ CONNECTED] osmo_stream_cli_read(): message received (stream.c:210) 20190412033755337 DLSS7 DEBUG asp-asp-clnt-OsmoMSC-A-Iu: xua_cli_read_cb(): sctp_recvmsg() returned 48 (flags=0x80) (osmo_ss7.c:1609) 20190412033755337 DLM3UA DEBUG asp-asp-clnt-OsmoMSC-A-Iu: Received M3UA Message (XFER:DATA) (m3ua.c:722) 20190412033755337 DLM3UA DEBUG asp-asp-clnt-OsmoMSC-A-Iu: m3ua_rx_xfer (m3ua.c:541) 20190412033755337 DLM3UA DEBUG asp-asp-clnt-OsmoMSC-A-Iu: m3ua_rx_xfer(): M3UA data header: opc=2236=1.23.4 dpc=2233=1.23.1 (m3ua.c:580) 20190412033755337 DLSS7 DEBUG m3ua_hmdc_rx_from_l2(): found dpc=2233=1.23.1 as local (osmo_ss7_hmrt.c:274) 20190412033755338 DLSS7 DEBUG scrc_rx_mtp_xfer_ind_xua: HDR=(CO:CODT,V=0,LEN=0), PART(T=Destination Reference,L=4,D=00000000), PART(T=Segmentation,L=4,D=00000000), PART(T=Data,L=6,D=000422040120) (sccp_scrc.c:450) 20190412033755338 DLSCCP NOTICE Cannot find connection for local reference 0 (sccp_scoc.c:1636) The same logging for the exact same code and situation, only with 2342 instead of 0x80000000: 20190412040110445 DBSSAP DEBUG ran_peer(GERAN-A:RI-SSN_PC:PC-1-23-4:SSN-BSSAP)[0x61200000aea0]{READY}: Outgoing conn id: 2342 (ran_conn.c:81) [...] 20190412040110451 DBSSAP DEBUG msc_t(IMSI-901700000014705:GERAN-A-2342:NONE)[0x61200001a920]{WAIT_HO_REQUEST_ACK}: NAS encode: BSSMAP: HANDOVER_REQUEST (nas_a.c:1159) 20190412040110451 DRR DEBUG ran_peer(GERAN-A:RI-SSN_PC:PC-1-23-4:SSN-BSSAP)[0x61200000aea0]{READY}: Received Event RAN_PEER_EV_MSG_DOWN_CO_INITIAL (ran_conn.c:119) 20190412040110451 DLSCCP DEBUG Received SCCP User Primitive (N-CONNECT.request) (sccp_scoc.c:1712) 20190412040110451 DLSCCP DEBUG SCCP-SCOC(2342)[0x61200001b820]{IDLE}: Allocated (fsm.c:423) 20190412040110451 DLSCCP DEBUG SCCP-SCOC(2342)[0x61200001b820]{IDLE}: Received Event N-CONNECT.req (sccp_scoc.c:1753) 20190412040110451 DLSS7 DEBUG sccp_scrc_rx_scoc_conn_msg: HDR=(CO:CORE,V=0,LEN=0), PART(T=Routing Context,L=4,D=00000000), PART(T=Protocol Class,L=4,D=00000002), PART(T=Source Reference,L=4,D=00000926), PART(T=Destination Address,L=20,D=0002000380020008000008bc80030008000000fe), PART(T=Sequence Control,L=4,D=00000000), PART(T=Source Address,L=20,D=0002000380020008000008b980030008000000fe), PART(T=Data,L=83,D=0051100b07010aa19181a5050a090086dc7f8e3f4115be12035058a605080062f224002a000005080009f1070046000104010c130a6014042f6500200240422c04080899100700001074507c06c0a80204a418) (sccp_scrc.c:398) 20190412040110451 DLSUA DEBUG sua_addr_parse_part(IEI=0x0103) (20) 00 02 00 03 80 02 00 08 00 00 08 bc 80 03 00 08 00 00 00 fe (sua.c:385) 20190412040110451 DLSUA DEBUG SUA IEI 0x0103 pos 4/20: subpart tag 0x8002, len 8 (sua.c:439) 20190412040110451 DLSUA DEBUG SUA IEI 0x0103 pos 12/20: subpart tag 0x8003, len 8 (sua.c:439) 20190412040110451 DLSUA DEBUG sua_addr_parse_part(IEI=0x0103) (20) 00 02 00 03 80 02 00 08 00 00 08 bc 80 03 00 08 00 00 00 fe (sua.c:385) 20190412040110451 DLSUA DEBUG SUA IEI 0x0103 pos 4/20: subpart tag 0x8002, len 8 (sua.c:439) 20190412040110452 DLSUA DEBUG SUA IEI 0x0103 pos 12/20: subpart tag 0x8003, len 8 (sua.c:439) 20190412040110452 DLSUA DEBUG sua_addr_parse_part(IEI=0x0102) (20) 00 02 00 03 80 02 00 08 00 00 08 b9 80 03 00 08 00 00 00 fe (sua.c:385) 20190412040110452 DLSUA DEBUG SUA IEI 0x0102 pos 4/20: subpart tag 0x8002, len 8 (sua.c:439) 20190412040110452 DLSUA DEBUG SUA IEI 0x0102 pos 12/20: subpart tag 0x8003, len 8 (sua.c:439) 20190412040110452 DLSS7 DEBUG m3ua_hmdc_rx_from_l2(): dpc=2236=1.23.4 not local, message is for routing (osmo_ss7_hmrt.c:278) 20190412040110452 DLSS7 DEBUG Found route for dpc=2236=1.23.4: pc=0=0.0.0 mask=0x0=0.0.0 via AS as-clnt-OsmoMSC-A-Iu proto=m3ua (osmo_ss7_hmrt.c:227) 20190412040110452 DLSS7 DEBUG rt->dest.as proto is M3UA for dpc=2236=1.23.4 (osmo_ss7_hmrt.c:233) 20190412040110452 DLSS7 DEBUG XUA_AS(as-clnt-OsmoMSC-A-Iu)[0x61200000a720]{AS_ACTIVE}: Received Event AS-TRANSFER.req (m3ua.c:507) 20190412040110452 DLSCCP DEBUG SCCP-SCOC(2342)[0x61200001b820]{IDLE}: State change to CONN_PEND_OUT (no timeout) (sccp_scoc.c:829) 20190412040110452 DLMGCP DEBUG mgw-endpoint(IMSI-901700000014705:GERAN-A-2342:NONE)[0x61200001ada0]{WAIT_MGW_RESPONSE}: rtpbridge/2@msc CI[0] RTP_TO_RAN CI=D1035D6D: CRCX: done (rtpbridge/2@msc:192.168.2.4:42008) (mgcp_client_endpoint_fsm.c:651) 20190412040110452 DLMGCP DEBUG mgw-endpoint(IMSI-901700000014705:GERAN-A-2342:NONE)[0x61200001ada0]{WAIT_MGW_RESPONSE}: rtpbridge/2@msc CI[1] RTP_TO_CN CI=A01EF28B: CRCX: done (rtpbridge/2@msc:192.168.2.4:42010) (mgcp_client_endpoint_fsm.c:651) 20190412040110452 DLMGCP DEBUG mgw-endpoint(IMSI-901700000014705:GERAN-A-2342:NONE)[0x61200001ada0]{WAIT_MGW_RESPONSE}: rtpbridge/2@msc CI in use: 2, waiting for response: 0 (mgcp_client_endpoint_fsm.c:669) 20190412040110452 DLMGCP DEBUG mgw-endpoint(IMSI-901700000014705:GERAN-A-2342:NONE)[0x61200001ada0]{WAIT_MGW_RESPONSE}: State change to IN_USE (no timeout) (mgcp_client_endpoint_fsm.c:680) 20190412040110452 DLMGCP DEBUG mgw-endpoint(IMSI-901700000014705:GERAN-A-2342:NONE)[0x61200001ada0]{IN_USE}: rtpbridge/2@msc CI[0] RTP_TO_RAN CI=D1035D6D: CRCX: done (rtpbridge/2@msc:192.168.2.4:42008) (mgcp_client_endpoint_fsm.c:651) 20190412040110452 DLMGCP DEBUG mgw-endpoint(IMSI-901700000014705:GERAN-A-2342:NONE)[0x61200001ada0]{IN_USE}: rtpbridge/2@msc CI[1] RTP_TO_CN CI=A01EF28B: CRCX: done (rtpbridge/2@msc:192.168.2.4:42010) (mgcp_client_endpoint_fsm.c:651) 20190412040110452 DLINP DEBUG [ CONNECTED] osmo_stream_cli_fd_cb(): connected write (stream.c:300) 20190412040110453 DLINP DEBUG [ CONNECTED] osmo_stream_cli_write(): sending data (stream.c:225) 20190412040110453 DLINP DEBUG [ CONNECTED] osmo_stream_cli_fd_cb(): connected write (stream.c:300) 20190412040110453 DLINP DEBUG [ CONNECTED] osmo_stream_cli_write(): sending data (stream.c:225) 20190412040110457 DLINP DEBUG [ CONNECTED] osmo_stream_cli_fd_cb(): connected read (stream.c:296) 20190412040110457 DLINP DEBUG [ CONNECTED] osmo_stream_cli_read(): message received (stream.c:210) 20190412040110457 DLSS7 DEBUG asp-asp-clnt-OsmoMSC-A-Iu: xua_cli_read_cb(): sctp_recvmsg() returned 48 (flags=0x80) (osmo_ss7.c:1609) 20190412040110457 DLM3UA DEBUG asp-asp-clnt-OsmoMSC-A-Iu: Received M3UA Message (XFER:DATA) (m3ua.c:722) 20190412040110457 DLM3UA DEBUG asp-asp-clnt-OsmoMSC-A-Iu: m3ua_rx_xfer (m3ua.c:541) 20190412040110457 DLM3UA DEBUG asp-asp-clnt-OsmoMSC-A-Iu: m3ua_rx_xfer(): M3UA data header: opc=2236=1.23.4 dpc=2233=1.23.1 (m3ua.c:580) 20190412040110457 DLSS7 DEBUG m3ua_hmdc_rx_from_l2(): found dpc=2233=1.23.1 as local (osmo_ss7_hmrt.c:274) 20190412040110457 DLSUA DEBUG IEI 259: Parsed Addr: RI=2,PC=2236,SSN=254 (sccp2sua.c:333) 20190412040110457 DLSS7 DEBUG scrc_rx_mtp_xfer_ind_xua: HDR=(CO:COAK,V=0,LEN=0), PART(T=Protocol Class,L=4,D=00000002), PART(T=Destination Reference,L=4,D=00000926), PART(T=Source Reference,L=4,D=00000000), PART(T=Destination Address,L=20,D=0002000380020008000008bc80030008000000fe) (sccp_scrc.c:450) [this is where above, the "Cannot find" error occurs] 20190412040110457 DLSCCP DEBUG Received CO:COAK for local reference 2342 (sccp_scoc.c:1645) 20190412040110457 DLSCCP DEBUG SCCP-SCOC(2342)[0x61200001b820]{CONN_PEND_OUT}: Received Event RCOC-CONNECT_CONFIRM.ind (sccp_scoc.c:1678) 20190412040110457 DLSCCP DEBUG SCCP-SCOC(2342)[0x61200001b820]{CONN_PEND_OUT}: State change to ACTIVE (no timeout) (sccp_scoc.c:980) 20190412040110458 DLSCCP DEBUG Delivering N-CONNECT.confirm to SCCP User 'OsmoMSC-A' (sccp_user.c:156) 20190412040110458 DBSSAP DEBUG (GERAN-A) sccp_ran_sap_up(N-CONNECT.confirm) (sccp_ran.c:143) 20190412040110464 DLINP DEBUG [ CONNECTED] osmo_stream_cli_fd_cb(): connected read (stream.c:296) 20190412040110464 DLINP DEBUG [ CONNECTED] osmo_stream_cli_read(): message received (stream.c:210) 20190412040110464 DLSS7 DEBUG asp-asp-clnt-OsmoMSC-A-Iu: xua_cli_read_cb(): sctp_recvmsg() returned 76 (flags=0x80) (osmo_ss7.c:1609) 20190412040110464 DLM3UA DEBUG asp-asp-clnt-OsmoMSC-A-Iu: Received M3UA Message (XFER:DATA) (m3ua.c:722) 20190412040110464 DLM3UA DEBUG asp-asp-clnt-OsmoMSC-A-Iu: m3ua_rx_xfer (m3ua.c:541) 20190412040110464 DLM3UA DEBUG asp-asp-clnt-OsmoMSC-A-Iu: m3ua_rx_xfer(): M3UA data header: opc=2236=1.23.4 dpc=2233=1.23.1 (m3ua.c:580) 20190412040110464 DLSS7 DEBUG m3ua_hmdc_rx_from_l2(): found dpc=2233=1.23.1 as local (osmo_ss7_hmrt.c:274) 20190412040110464 DLSS7 DEBUG scrc_rx_mtp_xfer_ind_xua: HDR=(CO:CODT,V=0,LEN=0), PART(T=Destination Reference,L=4,D=00000926), PART(T=Segmentation,L=4,D=00000000), PART(T=Data,L=34,D=002012170f062bc1660b2366010763410302280821982c0440217c06c0a8020359e4) (sccp_scrc.c:450) 20190412040110464 DLSCCP DEBUG Received CO:CODT for local reference 2342 (sccp_scoc.c:1645) 20190412040110464 DLSCCP DEBUG SCCP-SCOC(2342)[0x61200001b820]{ACTIVE}: Received Event RCOC-DT1.ind (sccp_scoc.c:1678) 20190412040110464 DLSCCP DEBUG Delivering N-DATA.indication to SCCP User 'OsmoMSC-A' (sccp_user.c:156) 20190412040110464 DBSSAP DEBUG (GERAN-A-2342) sccp_ran_sap_up(N-DATA.indication) (sccp_ran.c:106) 20190412040110464 DRR DEBUG ran_peer(GERAN-A:RI-SSN_PC:PC-1-23-4:SSN-BSSAP)[0x61200000aea0]{READY}: Received Event RAN_PEER_EV_MSG_UP_CO (ran_peer.c:529) 20190412040110464 DMSC DEBUG msc_t(IMSI-901700000014705:GERAN-A-2342:NONE)[0x61200001a920]{WAIT_HO_REQUEST_ACK}: Received Event MSC_EV_FROM_RAN_UP_L2 (ran_peer.c:346) 20190412040110464 DBSSAP DEBUG msc_t(IMSI-901700000014705:GERAN-A-2342:NONE)[0x61200001a920]{WAIT_HO_REQUEST_ACK}: NAS decode: BSSMAP: Rx BSSMAP DT1 HANDOVER REQ ACK (nas_a.c:779) I can only suspect that somewhere the value range is stripped?? I have pcaps for these two if anyone is interested. It was tested with current libosmo-sccp master, as well as with the last commit reverted ("sccp_scoc: conn_create{,_id}() user arg, not inst"), identical results. ~N

2 1

RFC: FSM instance IDs / log context / log filters
by Neels Hofmeyr 11 Apr '19

11 Apr '19

This is an idea about logging context, the logging filter and FSM instances. The idea is to make logging context a first-class citizen of osmo_fsm_inst and of LOGP(), in order to get cleaner FSM ids, better configurable logging and a more universal and reliable approach to logging filters. At events like 35c3 I want to, and hence any production operator wants to have useful filters for logging. The attempt with this RFC is to get this in an elegant way that also improves current logging context and saves FSM IDs. == Status quo == - Log filters: Since a long time ago, we have a logging filter mechanism which requires setting a global "context pointer" to some object, for every code path. It is not trivial to use and we mostly neglected using and testing it, so it doesn't work well in practice. See enum log_filter_index, enum log_ctx_index, log_set_context() in libosmocore and the filter_fn() in msc_main.c as an example. - Logging context: For a long time, we added logging context to each and every LOGP() line, like: LOGP(DMSC, LOGL_DEBUG, "(%s %s %d %d) Actual message", subscr->ctx1, osmo_foo_name(subscr->ctx2), trans->ctx3, another->ctx); Since the osmo_fsm_inst showed up, I have more and more used the FSM instance's id as logging context: #define LOG_MY_OBJ(my_obj, loglevel, fmt, args...) \ LOGPFSML(my_obj->fi, loglevel, fmt, ##args) my_obj_update_id(my_obj) { osmo_fsm_inst_update_id_f(my_obj->fi, "%s-%s-%d-%d", my_obj->ctx1, osmo_foo_name(my_obj->ctx2), my_obj->ctx3, my_obj->ctx); } stuff() { LOG_MY_OBJ(my_obj, LOGL_DEBUG, "Actual message"); } The advantages are obvious: - less time spent composing log message context when developing code. - context string is composed only once and re-used, less cpu cycles used to compose. - it is now made hard to forget adding useful log context. But this also has disadvantages: - Long lines Since I want to be able to trace logging output by various items, my logging context has often grown to a size that makes the log uncomfortable to read unless the terminal is really wide. For example, in osmo-msc, the context now often looks like this: DMSC DEBUG msc_a(IMSI-901700000014705:MSISDN-1001:TMSI-0x8D91D71B:GERAN-A-0:LU)[0x61200000b620]{MSC_A_ST_AUTH_CIPH}: Received Event MSC_A_EV_AUTHENTICATED (vlr_lu_fsm.c:741) It includes the IMSI, MSISDN, TMSI, the RAN conn info and the complete-l3 type. An extreme example is DCC DEBUG rtp_stream(IMSI-901700000014705:MSISDN-1001:TMSI-0x8D91D71B:GERAN-A-1:CM_SERVICE_REQ:trans-8:call-2147483649:RTP_TO_RAN:CI-BBBD5102:remote-port-not-sent:codec-not-sent:local-192-168-2-4-42000:remote-192-168-2-3-23004)[0x612000015e20]{ESTABLISHING}: Committing: Tx MDCX to update the MGW: updating remote-RTP-IP-port codec (rtp_stream.c:330) WTF. But of course, for an RTP stream, it is interesting to see what subscriber it is for, but also what callref and CC transaction, also the MGW's endpoint CI, whether it is to RAN or CN, and which RTP address and ports are involved. Now, a log line like this is pretty much guaranteed to be truncated in the display of gsmtap_log in wireshark. Very irritating. We would have to remove select items of logging context from the FSM instance ID to strike a good balance of length and usefulness. Each time we tweak it, all the logging output in test programs changes ... ugh. - Special characters Since an FSM instance can only have a limited set of characters for id, we can't add IP addresses as 1.2.3.4, but need to use 1-2-3-4. And so on and so on. - ID obfuscation If I want to address a specific osmo_fsm_inst on the CTRL interface, I need to pass the entire long id. I don't know of anyone using this in practice, but abusing the id as logging context makes this really hard. I think this is the worst side effect of me adding elaborate logging context to FSM instance ids. - log reading Various lengths of logging context make the log line's actual message show on various "indentation" levels. Instead I would like to be able to configure the log context part of a log message to show in the *end* of a log line instead of at the start, so that the short messages like "New conn" or "Rx Location Updating Request" show lined up one below each other; or alternatively introduce a common chunk of indentation spacing to line things up. That's currently not possible if both the log context and log message are just one arbitrary string fed to LOGP(). == IDEA == Reflecting on this, I formed the idea of moving logging context to a separate array of strings for each object. The most common usage would be to tie this array of context information to an osmo_fsm_inst. I'm not sure how far we could take this before we start producing too much load. It would of course be the aim to find a good balance of effort and usefulness, or think of nifty simplifications or optimizations. It's just a vague idea, but I guess it would look something like this in pseudo code: my_obj_update_id(my_obj) { set_log_context(my_obj->logctx, "IMSI", my_obj->imsi); set_log_context(my_obj->logctx, "MSISDN", my_obj->vlr->msisdn); set_log_context(my_obj->logctx, "RTP-local", osmo_sockaddr_str_name(my_obj->rtp_stream->rtp_local)); ... } set_log_context(ctx, name, val) { slot = log_context_find_or_create_slot(ctx, name); osmo_talloc_replace_str(ctx, &ctx[slot], val); /* or osmo_strlcpy() to a fixed-size char[]? */ } #define LOG_MY_OBJ(my_obj, level, fmt, args...) \ LOGP_CTX(DMSC, my_obj->ctx, level, fmt, ##args) use() { LOG_MY_OBJ(my_obj, LOGL_DEBUG, "Actual message"); /* i.e. most current log macros would be invoked in the same way */ } And then allow logging configuration like % hide all logging context in log output, except MSISDN and RTP-local: > logging print context none > logging print context MSISDN > logging print context RTP-local % show only logging lines where this exact IMSI is part of the context > logging filter-rule IMSI == 901700000014705 In gsmtap_log packets, we could add a listing of key-value items for log context, hopefully allowing to show / hide each individual context by name in a wireshark UI. Instead of repeating context like the IMSI in various FSM instance IDs, the logging context could be made chainable, i.e. internally, we could reference one logging context from another. For example, the rtp_stream FSM instance would only add the RTP address to its logging context, and then "upwards" reference the call_leg FSM's context. That would add the callref, and "upwards" reference the subscriber's context, which adds IMSI, MSISDN and RAN conn info to the rtp_stream logging context. (We might be able to do this implicitly from osmo_fsm_inst parent/child relations that we already have.) It might even be thinkable to allow traversing all across related context info, so that filtering for a given RTP port could cause even high level objects (like the vlr_subscr) to search through all childrens' log ctx information to see whether anyone defines this RTP-local context, thus show all logging for a conn that currently uses this RTP port. Premature optimization... To run each log line through a set of filters would potentially take up a lot of CPU cycles. For that I also have an idea to resolve the decision to log or not to log only once per target object and cache that result. For example, when I change the logging filter to pick a specific MSISDN, an internal token is incremented. If I hit an object's logging, I decide whether it passes the logging filter, and store the outcome as true/false with the current filter's token value in the object. Next time I hit that object and the token is still the same, the filter must also have the same result, and I can just use the stored true/false. If the user changes the filter, the token increments and on next logging, each object notices that the filter needs to be re-run in full. If the object's context info changes, reset the object's stored token to also rerun the filter on next logging. This is quite vague, especially not clear whether each object with logging context would have to store tokens for each and every log target separately... Premature optimization: require the log context names to be compile-time string literals, so that we can just compare name_a == name_b without invoking strcmp(). A general advantage is that we would always see the relevant context for logging, and we would immediately notice bugs in the context, thus we would always ensure reliable logging filters "for free". An easy way out of implementing log filters in osmocom would be to simply not have them, just provide well-defined log context in gsmtap_log, in a way that wireshark can parse. Users can then use wireshark rules to filter the log. The disadvantage here is that we would have to first compose all logging, instead of nicely skipping entire log lines before they are even composed. So, this is so far just an idea I would like to run by you. Even if the solutions might still be unworthy, I think it is worthwhile to be aware of the implications I highlighted above. ~N

2 2

LimeNet Micro as GSM BTS
by Rafael Diniz 11 Apr '19

11 Apr '19

1 0

Phones not registering on network
by Snehasish Kar 09 Apr '19

09 Apr '19

Hello I am trying to use openbsc with usrp x310. I have configured and executed osmo-trx from( https://github.com/osmocom/osmo-trx) and osmo-bts(https://github.com/osmocom/osmo-bts) and I can see the network on my phone but can't register to it, though I have set auth policy to accept-all. I have attached attached my config files for reference. BR Snehasish

5 5

Code coverage reports in Jenkins
by Vasil Velichkov 09 Apr '19

09 Apr '19

Hi Harald, Everyone, On 09/04/2019 09.32, Harald Welte wrote: > could you outline somewhere (mailinglist? maybe a wiki page?) how this > would work together? I've started adding code coverage support in changes 13496 and 13551 for OS#1987. Initially my goal was to generate reports only manually using gcov and lcov tools but after submitting my first change to gerrit I've noticed that Jenkins is used for CI/CD so I thought that it might be useful to generate these reports as part of the CI process. Jenkins has a Cobertura plugin [3] which collects coverage data in XML format [4], visualize them and track coverage metrics over time/builds. I've used lcov_cobertura tool to convert the lcov's coverage format to XML. > This Dockerfile which you're patching is used for build verification > of gerrit patches. Do you want to run coverage reports on every build > of every patch before commit? Yes, that was my idea. Other projects that I've used or contributed to in the past are using a workflow where code coverage data is generated in every CI build, then send to a coverage service, which analyze them and post message back in the PR about the coverage results - whether the coverage has increased, decrease, diff between reports, etc... For example see [1], [2], [5], [6] > I would argue it makes more sense to have coverage reports done once > per day? > In my opinion the coverage reports are more useful when they are closely integrated into the code review process and you receive information how coverage has changed together with the build status in the code review system. When reviewing a change the report could gives you more insights but still you should be able to merge it no matter what the coverage report says. If you find these reports not very useful during the code review process or the changes too disruptive to your workflow then we could build them once per day in the Osmocom_OBS_nightly (or another) job or not build them at all in the CI. BTW I just noticed that libosmocore is not built in the docker containers. Regards, Vasil [1] https://coveralls.io/github/neovim/neovim [2] https://codecov.io/gh/scrapy/scrapy [3] https://wiki.jenkins.io/display/JENKINS/Cobertura+Plugin [4] https://docs.openstack.org/infra/jenkins-job-builder/publishers.html#publis… [5] https://github.com/vlm/asn1c/pull/295#issuecomment-420464856 [6] https://github.com/mouse07410/asn1c/pull/22#issuecomment-298964785

1 0

minLatency() in osmo-trx
by Harald Welte 08 Apr '19

08 Apr '19

Dear all, the following question popped up on IRC: 22:08 < roh> is there some documentation how the minLatency() call in osmo-trx works? 22:10 < roh> it looks to me like the values we use for usrp1 and lms are not correct/cargocult I agree, the values are likely wrong for the non-UHD devices. Interestingly, they are auto-tuned at runtime, see the following piece in Transceiver.cpp: // if underrun hasn't occurred in the last sec (216 frames) drop // transmit latency by a timeslot if (mTransmitLatency > mRadioInterface->minLatency()) { if (radioClock->get() > mLatencyUpdateTime + GSM::Time(216,0)) { mTransmitLatency.decTN(); LOG(INFO) << "reduced latency: " << mTransmitLatency; mLatencyUpdateTime = radioClock->get(); } } However, that block only applies to devices with TX_WINDOW_USRP1 set, that is USRP1, B100 and B2xx devices. In fact, I cannot find any user of the minLatency() method outside the context of TX_WINDOW_USRP1, and hence I think it doesn't matter what kind of magic value the LMS driver supplies? So at least I conclude: * it's only ever used on USRP1, B100 and B2xx, and it is dynamically adjusted at runtime on those platforms Regards, Harald -- - Harald Welte <laforge(a)gnumonks.org> http://laforge.gnumonks.org/ ============================================================================ "Privacy in residential applications is a desirable marketing option." (ETSI EN 300 175-7 Ch. A6)

2 1

pySIM: hard-coded test expectations
by Vadim Yanitskiy 07 Apr '19

07 Apr '19

Hi all, I would like to get https://gerrit.osmocom.org/#/c/pysim/+/11491/ merged. Unfortunately, Jenkins always says no (V-1), because the expected test output is hard-coded somewhere on 'symtester' host. Please see: https://gerrit.osmocom.org/#/c/pysim/+/11491/ https://jenkins.osmocom.org/jenkins/job/gerrit-pysim/71/a1=default,a2=defau… https://jenkins.osmocom.org/jenkins/computer/simtester/ How can we proceed? As far as I can see, there are some *.ok files. It would (probably) make more sense to make them a part of the public pySym repository... With best regards, Vadim Yanitskiy.

2 1

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

OpenBSC April 2019