12 Apr
2019
12 Apr
'19
7:18 a.m.
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