Actions
Bug #6484
closeduse-after-free segfault at end of ttcn3 tests, in map_sccp_wait_cc_action()
Status:
Resolved
Priority:
Normal
Assignee:
-
Target version:
-
Start date:
06/06/2024
Due date:
% Done:
100%
Spec Reference:
Description
I am running ttcn3 tests to verify that https://gerrit.osmocom.org/c/osmo-hnbgw/+/36894 (hnb_persistent disconnected timeout) has no adverse effects.
Long after the new ttcn3 test has run and succeeded, and after a lot of other tests ran and succeeded, I get below segfault.
I doubt that it is caused by above patch, so far just recording the segfault in case it isn't reproducible:
20240606070047642 DCN DEBUG N-PCSTATE ind: affected_pc=185 sp_status=INACCESSIBLE remote_sccp_status=UNAVAILABLE_UNKNOWN (hnbgw_cn.c:557)
20240606070047642 DCN NOTICE (sgsn-0) now unreachable: N-PCSTATE ind: pc=185 sp_status=INACCESSIBLE remote_sccp_status=UNAVAILABLE_UNKNOWN (hnbgw_cn.c:620)
20240606070047642 DRANAP NOTICE cnlink(sgsn-0)[0x512000005020]{DISCONNECTED}: link lost (cnlink.c:118)
20240606070047642 DCN DEBUG sccp_sap_up(N-PCSTATE.indication) (hnbgw_cn.c:647)
20240606070047642 DCN DEBUG N-PCSTATE ind: affected_pc=10 sp_status=INACCESSIBLE remote_sccp_status=UNAVAILABLE_UNKNOWN (hnbgw_cn.c:557)
20240606070047642 DCN NOTICE (sgsn-1) now unreachable: N-PCSTATE ind: pc=10 sp_status=INACCESSIBLE remote_sccp_status=UNAVAILABLE_UNKNOWN (hnbgw_cn.c:620)
20240606070047642 DRANAP NOTICE cnlink(sgsn-1)[0x512000005320]{DISCONNECTED}: link lost (cnlink.c:118)
20240606070047642 DCN DEBUG sccp_sap_up(N-PCSTATE.indication) (hnbgw_cn.c:647)
20240606070047642 DCN DEBUG N-PCSTATE ind: affected_pc=2 sp_status=INACCESSIBLE remote_sccp_status=UNAVAILABLE_UNKNOWN (hnbgw_cn.c:557)
20240606070047642 DCN NOTICE (msc-1) now unreachable: N-PCSTATE ind: pc=2 sp_status=INACCESSIBLE remote_sccp_status=UNAVAILABLE_UNKNOWN (hnbgw_cn.c:620)
20240606070047642 DRANAP NOTICE cnlink(msc-1)[0x512000004720]{DISCONNECTED}: link lost (cnlink.c:118)
20240606070047642 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-37)[0x51200001af20]{connected}: Received Event MAP_SCCP_EV_RAN_LINK_LOST (context_map.c:189)
20240606070047642 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-37)[0x51200001af20]{connected}: State change to disconnected (X31, 5s) (context_map_sccp.c:382)
20240606070047643 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-12599569)[0x51200001ada0]{connected}: Received Event MAP_RUA_EV_CN_DISC (context_map_sccp.c:465)
20240606070047643 DHNB INFO map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-12599569)[0x51200001ada0]{connected}: Tx RUA Disconnect (context_map_rua.c:262)
20240606070047643 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-12599569)[0x51200001ada0]{connected}: State change to disrupted (X31, 5s) (context_map_rua.c:305)
20240606070047643 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-12599569)[0x51200001ada0]{disrupted}: Terminating (cause = OSMO_FSM_TERM_REGULAR) (context_map.c:202)
20240606070047643 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-12599569)[0x51200001ada0]{disrupted}: Freeing instance (context_map.c:202)
20240606070047643 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-12599569)[0x51200001ada0]{disrupted}: Deallocated (fsm.c:568)
20240606070047643 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-37)[0x51200001af20]{disconnected}: Terminating (cause = OSMO_FSM_TERM_REGULAR) (context_map.c:206)
20240606070047643 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-37)[0x51200001af20]{disconnected}: Freeing instance (context_map.c:206)
20240606070047643 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-37)[0x51200001af20]{disconnected}: Deallocated (fsm.c:568)
20240606070047643 DMAIN INFO (127.0.1.1:9999 TTCN3-HNB-0) RUA-12599569 SCCP-37 msc-1 MI=TMSI-0x42400023: Deallocating (context_map.c:225)
20240606070047643 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-38)[0x51200001b3a0]{connected}: Received Event MAP_SCCP_EV_RAN_LINK_LOST (context_map.c:189)
20240606070047643 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-38)[0x51200001b3a0]{connected}: State change to disconnected (X31, 5s) (context_map_sccp.c:382)
20240606070047643 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-4010700)[0x51200001b220]{connected}: Received Event MAP_RUA_EV_CN_DISC (context_map_sccp.c:465)
20240606070047643 DHNB INFO map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-4010700)[0x51200001b220]{connected}: Tx RUA Disconnect (context_map_rua.c:262)
20240606070047643 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-4010700)[0x51200001b220]{connected}: State change to disrupted (X31, 5s) (context_map_rua.c:305)
20240606070047643 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-4010700)[0x51200001b220]{disrupted}: Terminating (cause = OSMO_FSM_TERM_REGULAR) (context_map.c:202)
20240606070047643 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-4010700)[0x51200001b220]{disrupted}: Freeing instance (context_map.c:202)
20240606070047643 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-4010700)[0x51200001b220]{disrupted}: Deallocated (fsm.c:568)
20240606070047643 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-38)[0x51200001b3a0]{disconnected}: Terminating (cause = OSMO_FSM_TERM_REGULAR) (context_map.c:206)
20240606070047643 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-38)[0x51200001b3a0]{disconnected}: Freeing instance (context_map.c:206)
20240606070047643 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-38)[0x51200001b3a0]{disconnected}: Deallocated (fsm.c:568)
20240606070047644 DMAIN INFO (127.0.1.1:9999 TTCN3-HNB-0) RUA-4010700 SCCP-38 msc-1 MI=TMSI-0x42410023: Deallocating (context_map.c:225)
20240606070047644 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-39)[0x51200001b820]{connected}: Received Event MAP_SCCP_EV_RAN_LINK_LOST (context_map.c:189)
20240606070047644 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-39)[0x51200001b820]{connected}: State change to disconnected (X31, 5s) (context_map_sccp.c:382)
20240606070047644 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-9583615)[0x51200001b6a0]{connected}: Received Event MAP_RUA_EV_CN_DISC (context_map_sccp.c:465)
20240606070047644 DHNB INFO map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-9583615)[0x51200001b6a0]{connected}: Tx RUA Disconnect (context_map_rua.c:262)
20240606070047644 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-9583615)[0x51200001b6a0]{connected}: State change to disrupted (X31, 5s) (context_map_rua.c:305)
20240606070047644 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-9583615)[0x51200001b6a0]{disrupted}: Terminating (cause = OSMO_FSM_TERM_REGULAR) (context_map.c:202)
20240606070047644 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-9583615)[0x51200001b6a0]{disrupted}: Freeing instance (context_map.c:202)
20240606070047644 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-9583615)[0x51200001b6a0]{disrupted}: Deallocated (fsm.c:568)
20240606070047644 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-39)[0x51200001b820]{disconnected}: Terminating (cause = OSMO_FSM_TERM_REGULAR) (context_map.c:206)
20240606070047644 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-39)[0x51200001b820]{disconnected}: Freeing instance (context_map.c:206)
20240606070047644 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-39)[0x51200001b820]{disconnected}: Deallocated (fsm.c:568)
20240606070047644 DMAIN INFO (127.0.1.1:9999 TTCN3-HNB-0) RUA-9583615 SCCP-39 msc-1 MI=TMSI-0x427FC023: Deallocating (context_map.c:225)
20240606070047644 DMAIN NOTICE (127.0.1.1:9999 TTCN3-HNB-0) sctp_recvmsg(r=127.0.1.1:9999<->l=127.0.0.1:29169) = SCTP_SHUTDOWN_EVENT, closing conn (hnbgw.c:793)
20240606070047644 DMAIN INFO (disconnected TTCN3-HNB-0) Releasing HNB context (hnbgw.c:351)
20240606070047654 DLGLOBAL INFO Closing telnet connection r=127.0.0.1:40206<->l=127.0.0.1:4261 (telnet_interface.c:138)
20240606070047987 DLGLOBAL INFO Accept()ed new telnet connection r=127.0.0.1:40232<->l=127.0.0.1:4261 (telnet_interface.c:192)
20240606070048210 DMAIN INFO New HNB SCTP connection r=127.0.1.1:9999<->l=127.0.0.1:29169 (hnbgw.c:873)
20240606070048617 DLGLOBAL INFO Accept()ed new telnet connection r=127.0.0.1:53964<->l=127.0.0.1:4261 (telnet_interface.c:192)
20240606070048694 DMAIN INFO New HNB SCTP connection r=127.0.1.2:36753<->l=127.0.0.1:29169 (hnbgw.c:873)
20240606070048848 DLCTRL INFO accept()ed new CTRL connection from (r=127.0.0.1:37943<->l=127.0.0.1:4262) (control_if.c:570)
20240606070048938 DCN NOTICE (msc-0) VTY requests BSSMAP RESET (hnbgw_vty.c:789)
20240606070048940 DCN NOTICE (msc-1) VTY requests BSSMAP RESET (hnbgw_vty.c:789)
20240606070048948 DCN NOTICE (msc-2) VTY requests BSSMAP RESET (hnbgw_vty.c:789)
20240606070048951 DCN NOTICE (msc-3) VTY requests BSSMAP RESET (hnbgw_vty.c:789)
20240606070049870 DCN DEBUG sccp_sap_up(N-PCSTATE.indication) (hnbgw_cn.c:647)
20240606070049870 DCN DEBUG N-PCSTATE ind: affected_pc=188 sp_status=ACCESSIBLE remote_sccp_status=AVAILABLE (hnbgw_cn.c:557)
20240606070049870 DCN NOTICE (msc-0) now available: N-PCSTATE ind: pc=188 sp_status=ACCESSIBLE remote_sccp_status=AVAILABLE (hnbgw_cn.c:628)
20240606070050321 DCN DEBUG sccp_sap_up(N-PCSTATE.indication) (hnbgw_cn.c:647)
20240606070050321 DCN DEBUG N-PCSTATE ind: affected_pc=2 sp_status=ACCESSIBLE remote_sccp_status=AVAILABLE (hnbgw_cn.c:557)
20240606070050321 DCN NOTICE (msc-1) now available: N-PCSTATE ind: pc=2 sp_status=ACCESSIBLE remote_sccp_status=AVAILABLE (hnbgw_cn.c:628)
20240606070050385 DCN NOTICE (sgsn-0) VTY requests BSSMAP RESET (hnbgw_vty.c:789)
20240606070050404 DCN NOTICE (sgsn-1) VTY requests BSSMAP RESET (hnbgw_vty.c:789)
20240606070050409 DCN NOTICE (sgsn-2) VTY requests BSSMAP RESET (hnbgw_vty.c:789)
20240606070050430 DCN NOTICE (sgsn-3) VTY requests BSSMAP RESET (hnbgw_vty.c:789)
20240606070050511 DCN DEBUG sccp_sap_up(N-PCSTATE.indication) (hnbgw_cn.c:647)
20240606070050511 DCN DEBUG N-PCSTATE ind: affected_pc=3 sp_status=ACCESSIBLE remote_sccp_status=AVAILABLE (hnbgw_cn.c:557)
20240606070050511 DCN NOTICE (msc-2) now available: N-PCSTATE ind: pc=3 sp_status=ACCESSIBLE remote_sccp_status=AVAILABLE (hnbgw_cn.c:628)
20240606070050928 DCN DEBUG sccp_sap_up(N-UNITDATA.indication) (hnbgw_cn.c:647)
20240606070050928 DRANAP NOTICE (msc-0) Tx RANAP RESET ACK IuCS RI=SSN_PC,PC=0.23.5,SSN=RANAP --> RI=SSN_PC,PC=0.23.4,SSN=RANAP (cnlink.c:197)
20240606070050928 DRANAP NOTICE cnlink(msc-0)[0x512000004420]{CONNECTED}: link up (cnlink.c:111)
20240606070050946 DCN DEBUG sccp_sap_up(N-UNITDATA.indication) (hnbgw_cn.c:647)
20240606070050946 DRANAP INFO cnlink(msc-0)[0x512000004420]{CONNECTED}: Link is already up, ignoring RESET ACK (cnlink.c:282)
20240606070051234 DCN DEBUG sccp_sap_up(N-UNITDATA.indication) (hnbgw_cn.c:647)
20240606070051235 DRANAP NOTICE (msc-1) Tx RANAP RESET ACK IuCS RI=SSN_PC,PC=0.23.5,SSN=RANAP --> RI=SSN_PC,PC=0.0.2,SSN=RANAP (cnlink.c:197)
20240606070051235 DRANAP NOTICE cnlink(msc-1)[0x512000004720]{CONNECTED}: link up (cnlink.c:111)
20240606070051260 DCN DEBUG sccp_sap_up(N-PCSTATE.indication) (hnbgw_cn.c:647)
20240606070051260 DCN DEBUG N-PCSTATE ind: affected_pc=185 sp_status=ACCESSIBLE remote_sccp_status=AVAILABLE (hnbgw_cn.c:557)
20240606070051260 DCN NOTICE (sgsn-0) now available: N-PCSTATE ind: pc=185 sp_status=ACCESSIBLE remote_sccp_status=AVAILABLE (hnbgw_cn.c:628)
20240606070051359 DCN DEBUG sccp_sap_up(N-UNITDATA.indication) (hnbgw_cn.c:647)
20240606070051362 DRANAP INFO cnlink(msc-1)[0x512000004720]{CONNECTED}: Link is already up, ignoring RESET ACK (cnlink.c:282)
20240606070051630 DCN DEBUG sccp_sap_up(N-UNITDATA.indication) (hnbgw_cn.c:647)
20240606070051630 DRANAP NOTICE (msc-2) Tx RANAP RESET ACK IuCS RI=SSN_PC,PC=0.23.5,SSN=RANAP --> RI=SSN_PC,PC=0.0.3,SSN=RANAP (cnlink.c:197)
20240606070051630 DRANAP NOTICE cnlink(msc-2)[0x512000004a20]{CONNECTED}: link up (cnlink.c:111)
20240606070051701 DCN DEBUG sccp_sap_up(N-UNITDATA.indication) (hnbgw_cn.c:647)
20240606070051701 DRANAP INFO cnlink(msc-2)[0x512000004a20]{CONNECTED}: Link is already up, ignoring RESET ACK (cnlink.c:282)
20240606070051898 DCN DEBUG sccp_sap_up(N-PCSTATE.indication) (hnbgw_cn.c:647)
20240606070051901 DCN DEBUG N-PCSTATE ind: affected_pc=10 sp_status=ACCESSIBLE remote_sccp_status=AVAILABLE (hnbgw_cn.c:557)
20240606070051901 DCN NOTICE (sgsn-1) now available: N-PCSTATE ind: pc=10 sp_status=ACCESSIBLE remote_sccp_status=AVAILABLE (hnbgw_cn.c:628)
20240606070051929 DMAIN DEBUG Decoding message HNBAP_HNBRegisterRequestIEs (hnbap_decoder.c:22) (hnbap_decoder.c:22)
20240606070051929 DHNBAP DEBUG (127.0.1.1:9999 TTCN3-HNB-0) HNB-REGISTER-REQ TTCN3-HNB-0 001-01-L2342-R0-S55-C1 (hnbgw_hnbap.c:561)
20240606070051930 DHNBAP NOTICE (127.0.1.1:9999 TTCN3-HNB-0) HNB (re)connecting, discarding all previous UE state (hnbgw_hnbap.c:567)
20240606070051930 DHNBAP NOTICE (127.0.1.1:9999 TTCN3-HNB-0) Accepting HNB-REGISTER-REQ (hnbgw_hnbap.c:168)
20240606070051999 DMAIN DEBUG Decoding message HNBAP_HNBRegisterRequestIEs (hnbap_decoder.c:22) (hnbap_decoder.c:22)
20240606070051999 DHNBAP DEBUG (127.0.1.2:36753 TTCN3-HNB-1) HNB-REGISTER-REQ TTCN3-HNB-1 001-01-L2343-R0-S55-C2 (hnbgw_hnbap.c:561)
20240606070052005 DHNBAP NOTICE (127.0.1.2:36753 TTCN3-HNB-1) HNB (re)connecting, discarding all previous UE state (hnbgw_hnbap.c:567)
20240606070052005 DHNBAP NOTICE (127.0.1.2:36753 TTCN3-HNB-1) Accepting HNB-REGISTER-REQ (hnbgw_hnbap.c:168)
20240606070052023 DCN DEBUG sccp_sap_up(N-PCSTATE.indication) (hnbgw_cn.c:647)
20240606070052023 DCN DEBUG N-PCSTATE ind: affected_pc=11 sp_status=ACCESSIBLE remote_sccp_status=AVAILABLE (hnbgw_cn.c:557)
20240606070052023 DCN NOTICE (sgsn-2) now available: N-PCSTATE ind: pc=11 sp_status=ACCESSIBLE remote_sccp_status=AVAILABLE (hnbgw_cn.c:628)
20240606070052204 DCN DEBUG sccp_sap_up(N-UNITDATA.indication) (hnbgw_cn.c:647)
20240606070052205 DRANAP NOTICE (sgsn-0) Tx RANAP RESET ACK IuPS RI=SSN_PC,PC=0.23.5,SSN=RANAP --> RI=SSN_PC,PC=0.23.1,SSN=RANAP (cnlink.c:197)
20240606070052205 DRANAP NOTICE cnlink(sgsn-0)[0x512000005020]{CONNECTED}: link up (cnlink.c:111)
20240606070052334 DCN DEBUG sccp_sap_up(N-UNITDATA.indication) (hnbgw_cn.c:647)
20240606070052334 DRANAP INFO cnlink(sgsn-0)[0x512000005020]{CONNECTED}: Link is already up, ignoring RESET ACK (cnlink.c:282)
20240606070052550 DCN DEBUG sccp_sap_up(N-UNITDATA.indication) (hnbgw_cn.c:647)
20240606070052550 DRANAP NOTICE (sgsn-1) Tx RANAP RESET ACK IuPS RI=SSN_PC,PC=0.23.5,SSN=RANAP --> RI=SSN_PC,PC=0.1.2,SSN=RANAP (cnlink.c:197)
20240606070052550 DRANAP NOTICE cnlink(sgsn-1)[0x512000005320]{CONNECTED}: link up (cnlink.c:111)
20240606070052560 DCN DEBUG sccp_sap_up(N-UNITDATA.indication) (hnbgw_cn.c:647)
20240606070052561 DRANAP INFO cnlink(sgsn-1)[0x512000005320]{CONNECTED}: Link is already up, ignoring RESET ACK (cnlink.c:282)
20240606070052919 DCN DEBUG sccp_sap_up(N-UNITDATA.indication) (hnbgw_cn.c:647)
20240606070052919 DRANAP NOTICE (sgsn-2) Tx RANAP RESET ACK IuPS RI=SSN_PC,PC=0.23.5,SSN=RANAP --> RI=SSN_PC,PC=0.1.3,SSN=RANAP (cnlink.c:197)
20240606070052919 DRANAP NOTICE cnlink(sgsn-2)[0x512000005620]{CONNECTED}: link up (cnlink.c:111)
20240606070052942 DCN DEBUG sccp_sap_up(N-UNITDATA.indication) (hnbgw_cn.c:647)
20240606070052942 DRANAP INFO cnlink(sgsn-2)[0x512000005620]{CONNECTED}: Link is already up, ignoring RESET ACK (cnlink.c:282)
20240606070054064 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:new (control_cmd.c:428)
20240606070054082 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:known (control_cmd.c:428)
20240606070054088 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:reattach (control_cmd.c:428)
20240606070054095 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:attach_lost (control_cmd.c:428)
20240606070054100 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:paged (control_cmd.c:428)
20240606070054106 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:new (control_cmd.c:428)
20240606070054111 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:known (control_cmd.c:428)
20240606070054115 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:reattach (control_cmd.c:428)
20240606070054120 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:attach_lost (control_cmd.c:428)
20240606070054124 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:paged (control_cmd.c:428)
20240606070054128 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:new (control_cmd.c:428)
20240606070054131 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:known (control_cmd.c:428)
20240606070054136 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:reattach (control_cmd.c:428)
20240606070054140 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:attach_lost (control_cmd.c:428)
20240606070054143 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:paged (control_cmd.c:428)
20240606070054147 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:new (control_cmd.c:428)
20240606070054151 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:known (control_cmd.c:428)
20240606070054156 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:reattach (control_cmd.c:428)
20240606070054159 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:attach_lost (control_cmd.c:428)
20240606070054161 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:paged (control_cmd.c:428)
20240606070054202 DLGLOBAL INFO Accept()ed new telnet connection r=127.0.0.1:53970<->l=127.0.0.1:4261 (telnet_interface.c:192)
20240606070055273 DMAIN DEBUG Decoding message RUA_ConnectIEs (rua_decoder.c:22) (rua_decoder.c:22)
20240606070055273 DHNB DEBUG map_rua[0x51200001bb20]{init}: Allocated (fsm.c:456)
20240606070055273 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-7994758)[0x51200001bb20]{init}: State change to init (X31, 5s) (context_map_rua.c:85)
20240606070055274 DCN INFO (127.0.1.1:9999 TTCN3-HNB-0) RUA-7994758 SCCP-0 CS MI=TMSI-0x42800023: TMSI-0x42800023 NRI(10bit)=0x200=512: NRI match selects msc 2 (hnbgw_cn.c:1067)
20240606070055274 DCN DEBUG map_sccp[0x51200001bca0]{init}: Allocated (fsm.c:456)
20240606070055274 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-40)[0x51200001bca0]{init}: State change to init (X31, 5s) (context_map_sccp.c:93)
20240606070055274 DRUA NOTICE New conn: r=127.0.1.1:9999<->l=127.0.0.1:29169 '127.0.1.1:9999 TTCN3-HNB-0' RUA-7994758 <-> SCCP-40 msc-2 msc-two cs7-0.sccp l=0.23.5<->r=0.0.3 (context_map.c:128)
20240606070055274 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-7994758)[0x51200001bb20]{init}: Received Event MAP_RUA_EV_RX_CONNECT (hnbgw_rua.c:299)
20240606070055274 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-7994758)[0x51200001bb20]{init}: rx from RUA: RANAP Initial UE Message (context_map_rua.c:166)
20240606070055274 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-40)[0x51200001bca0]{init}: Received Event MAP_SCCP_EV_TX_DATA_REQUEST (context_map_rua.c:194)
20240606070055274 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-40)[0x51200001bca0]{init}: State change to wait_cc (X31, 5s) (context_map_sccp.c:272)
20240606070055274 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-7994758)[0x51200001bb20]{init}: State change to connected (no timeout) (context_map_rua.c:224)
20240606070055291 DCN DEBUG sccp_sap_up(N-CONNECT.confirm) (hnbgw_cn.c:647)
20240606070055291 DCN DEBUG handle_cn_conn_conf() conn_id=40, addrs: called=RI=SSN_PC,PC=0.0.3,SSN=RANAP calling=RI=SSN_PC,PC=0.23.5,SSN=RANAP responding=RI=NONE (hnbgw_cn.c:483)
20240606070055291 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-40)[0x51200001bca0]{wait_cc}: Received Event MAP_SCCP_EV_RX_CONNECTION_CONFIRM (hnbgw_cn.c:489)
20240606070055291 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-40)[0x51200001bca0]{wait_cc}: State change to connected (no timeout) (context_map_sccp.c:304)
20240606070055293 DLGLOBAL INFO Closing telnet connection r=127.0.0.1:53970<->l=127.0.0.1:4261 (telnet_interface.c:138)
20240606070055295 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:new (control_cmd.c:428)
20240606070055297 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:known (control_cmd.c:428)
20240606070055299 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:reattach (control_cmd.c:428)
20240606070055301 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:attach_lost (control_cmd.c:428)
20240606070055303 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:paged (control_cmd.c:428)
20240606070055305 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:new (control_cmd.c:428)
20240606070055307 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:known (control_cmd.c:428)
20240606070055309 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:reattach (control_cmd.c:428)
20240606070055311 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:attach_lost (control_cmd.c:428)
20240606070055312 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:paged (control_cmd.c:428)
20240606070055314 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:new (control_cmd.c:428)
20240606070055316 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:known (control_cmd.c:428)
20240606070055318 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:reattach (control_cmd.c:428)
20240606070055320 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:attach_lost (control_cmd.c:428)
20240606070055322 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:paged (control_cmd.c:428)
20240606070055324 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:new (control_cmd.c:428)
20240606070055326 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:known (control_cmd.c:428)
20240606070055327 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:reattach (control_cmd.c:428)
20240606070055329 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:attach_lost (control_cmd.c:428)
20240606070055331 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:paged (control_cmd.c:428)
20240606070055382 DLGLOBAL INFO Accept()ed new telnet connection r=127.0.0.1:53974<->l=127.0.0.1:4261 (telnet_interface.c:192)
20240606070056418 DMAIN DEBUG Decoding message RUA_ConnectIEs (rua_decoder.c:22) (rua_decoder.c:22)
20240606070056419 DHNB DEBUG map_rua[0x512000020020]{init}: Allocated (fsm.c:456)
20240606070056419 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-291557)[0x512000020020]{init}: State change to init (X31, 5s) (context_map_rua.c:85)
20240606070056419 DCN INFO (127.0.1.1:9999 TTCN3-HNB-0) RUA-291557 SCCP-0 CS MI=TMSI-0x42A98023: TMSI-0x42A98023 NRI(10bit)=0x2a6=678: NRI match selects msc 2 (hnbgw_cn.c:1067)
20240606070056419 DCN DEBUG map_sccp[0x5120000201a0]{init}: Allocated (fsm.c:456)
20240606070056419 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-41)[0x5120000201a0]{init}: State change to init (X31, 5s) (context_map_sccp.c:93)
20240606070056419 DRUA NOTICE New conn: r=127.0.1.1:9999<->l=127.0.0.1:29169 '127.0.1.1:9999 TTCN3-HNB-0' RUA-291557 <-> SCCP-41 msc-2 msc-two cs7-0.sccp l=0.23.5<->r=0.0.3 (context_map.c:128)
20240606070056419 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-291557)[0x512000020020]{init}: Received Event MAP_RUA_EV_RX_CONNECT (hnbgw_rua.c:299)
20240606070056419 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-291557)[0x512000020020]{init}: rx from RUA: RANAP Initial UE Message (context_map_rua.c:166)
20240606070056420 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-41)[0x5120000201a0]{init}: Received Event MAP_SCCP_EV_TX_DATA_REQUEST (context_map_rua.c:194)
20240606070056420 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-41)[0x5120000201a0]{init}: State change to wait_cc (X31, 5s) (context_map_sccp.c:272)
20240606070056420 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-291557)[0x512000020020]{init}: State change to connected (no timeout) (context_map_rua.c:224)
20240606070056427 DCN DEBUG sccp_sap_up(N-CONNECT.confirm) (hnbgw_cn.c:647)
20240606070056427 DCN DEBUG handle_cn_conn_conf() conn_id=41, addrs: called=RI=SSN_PC,PC=0.0.3,SSN=RANAP calling=RI=SSN_PC,PC=0.23.5,SSN=RANAP responding=RI=NONE (hnbgw_cn.c:483)
20240606070056427 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-41)[0x5120000201a0]{wait_cc}: Received Event MAP_SCCP_EV_RX_CONNECTION_CONFIRM (hnbgw_cn.c:489)
20240606070056427 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-41)[0x5120000201a0]{wait_cc}: State change to connected (no timeout) (context_map_sccp.c:304)
20240606070056434 DLGLOBAL INFO Closing telnet connection r=127.0.0.1:53974<->l=127.0.0.1:4261 (telnet_interface.c:138)
20240606070056436 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:new (control_cmd.c:428)
20240606070056439 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:known (control_cmd.c:428)
20240606070056442 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:reattach (control_cmd.c:428)
20240606070056444 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:attach_lost (control_cmd.c:428)
20240606070056447 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:paged (control_cmd.c:428)
20240606070056451 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:new (control_cmd.c:428)
20240606070056454 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:known (control_cmd.c:428)
20240606070056457 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:reattach (control_cmd.c:428)
20240606070056459 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:attach_lost (control_cmd.c:428)
20240606070056462 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:paged (control_cmd.c:428)
20240606070056465 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:new (control_cmd.c:428)
20240606070056468 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:known (control_cmd.c:428)
20240606070056470 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:reattach (control_cmd.c:428)
20240606070056473 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:attach_lost (control_cmd.c:428)
20240606070056477 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:paged (control_cmd.c:428)
20240606070056480 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:new (control_cmd.c:428)
20240606070056484 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:known (control_cmd.c:428)
20240606070056488 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:reattach (control_cmd.c:428)
20240606070056491 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:attach_lost (control_cmd.c:428)
20240606070056494 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:paged (control_cmd.c:428)
20240606070056584 DLGLOBAL INFO Accept()ed new telnet connection r=127.0.0.1:53976<->l=127.0.0.1:4261 (telnet_interface.c:192)
20240606070057626 DMAIN DEBUG Decoding message RUA_ConnectIEs (rua_decoder.c:22) (rua_decoder.c:22)
20240606070057626 DHNB DEBUG map_rua[0x5120000204a0]{init}: Allocated (fsm.c:456)
20240606070057626 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-15282514)[0x5120000204a0]{init}: State change to init (X31, 5s) (context_map_rua.c:85)
20240606070057626 DCN INFO (127.0.1.1:9999 TTCN3-HNB-0) RUA-15282514 SCCP-0 CS MI=IMSI-262420000000001: CN link round-robin selects msc 1 (hnbgw_cn.c:1114)
20240606070057626 DCN DEBUG map_sccp[0x512000020620]{init}: Allocated (fsm.c:456)
20240606070057626 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-42)[0x512000020620]{init}: State change to init (X31, 5s) (context_map_sccp.c:93)
20240606070057626 DRUA NOTICE New conn: r=127.0.1.1:9999<->l=127.0.0.1:29169 '127.0.1.1:9999 TTCN3-HNB-0' RUA-15282514 <-> SCCP-42 msc-1 msc-one cs7-0.sccp l=0.23.5<->r=0.0.2 (context_map.c:128)
20240606070057626 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-15282514)[0x5120000204a0]{init}: Received Event MAP_RUA_EV_RX_CONNECT (hnbgw_rua.c:299)
20240606070057627 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-15282514)[0x5120000204a0]{init}: rx from RUA: RANAP Initial UE Message (context_map_rua.c:166)
20240606070057627 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-42)[0x512000020620]{init}: Received Event MAP_SCCP_EV_TX_DATA_REQUEST (context_map_rua.c:194)
20240606070057627 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-42)[0x512000020620]{init}: State change to wait_cc (X31, 5s) (context_map_sccp.c:272)
20240606070057627 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-15282514)[0x5120000204a0]{init}: State change to connected (no timeout) (context_map_rua.c:224)
20240606070057658 DLGLOBAL INFO Closing telnet connection r=127.0.0.1:53976<->l=127.0.0.1:4261 (telnet_interface.c:138)
20240606070057660 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:new (control_cmd.c:428)
20240606070057668 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:known (control_cmd.c:428)
20240606070057672 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:reattach (control_cmd.c:428)
20240606070057676 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:attach_lost (control_cmd.c:428)
20240606070057678 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.0.cnpool:subscr:paged (control_cmd.c:428)
20240606070057683 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:new (control_cmd.c:428)
20240606070057690 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:known (control_cmd.c:428)
20240606070057697 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:reattach (control_cmd.c:428)
20240606070057700 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:attach_lost (control_cmd.c:428)
20240606070057704 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.1.cnpool:subscr:paged (control_cmd.c:428)
20240606070057706 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:new (control_cmd.c:428)
20240606070057708 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:known (control_cmd.c:428)
20240606070057710 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:reattach (control_cmd.c:428)
20240606070057712 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:attach_lost (control_cmd.c:428)
20240606070057714 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.2.cnpool:subscr:paged (control_cmd.c:428)
20240606070057717 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:new (control_cmd.c:428)
20240606070057720 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:known (control_cmd.c:428)
20240606070057722 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:reattach (control_cmd.c:428)
20240606070057724 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:attach_lost (control_cmd.c:428)
20240606070057726 DLCTRL DEBUG Command: GET rate_ctr.abs.msc.3.cnpool:subscr:paged (control_cmd.c:428)
20240606070057735 DLGLOBAL INFO Closing telnet connection r=127.0.0.1:40232<->l=127.0.0.1:4261 (telnet_interface.c:138)
20240606070057752 DMAIN NOTICE (127.0.1.2:36753 TTCN3-HNB-1) sctp_recvmsg(r=127.0.1.2:36753<->l=127.0.0.1:29169) = SCTP_SHUTDOWN_EVENT, closing conn (hnbgw.c:793)
20240606070057752 DMAIN INFO (disconnected TTCN3-HNB-1) Releasing HNB context (hnbgw.c:351)
20240606070057752 DLCTRL INFO close()d CTRL connection (r=127.0.0.1:37943<->l=127.0.0.1:4262) (control_if.c:193)
20240606070057769 DCN DEBUG sccp_sap_up(N-PCSTATE.indication) (hnbgw_cn.c:647)
20240606070057769 DCN DEBUG N-PCSTATE ind: affected_pc=188 sp_status=INACCESSIBLE remote_sccp_status=UNAVAILABLE_UNKNOWN (hnbgw_cn.c:557)
20240606070057769 DCN NOTICE (msc-0) now unreachable: N-PCSTATE ind: pc=188 sp_status=INACCESSIBLE remote_sccp_status=UNAVAILABLE_UNKNOWN (hnbgw_cn.c:620)
20240606070057769 DRANAP NOTICE cnlink(msc-0)[0x512000004420]{DISCONNECTED}: link lost (cnlink.c:118)
20240606070057769 DCN DEBUG sccp_sap_up(N-PCSTATE.indication) (hnbgw_cn.c:647)
20240606070057769 DCN DEBUG N-PCSTATE ind: affected_pc=3 sp_status=INACCESSIBLE remote_sccp_status=UNAVAILABLE_UNKNOWN (hnbgw_cn.c:557)
20240606070057769 DCN NOTICE (msc-2) now unreachable: N-PCSTATE ind: pc=3 sp_status=INACCESSIBLE remote_sccp_status=UNAVAILABLE_UNKNOWN (hnbgw_cn.c:620)
20240606070057769 DRANAP NOTICE cnlink(msc-2)[0x512000004a20]{DISCONNECTED}: link lost (cnlink.c:118)
20240606070057769 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-40)[0x51200001bca0]{connected}: Received Event MAP_SCCP_EV_RAN_LINK_LOST (context_map.c:189)
20240606070057769 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-40)[0x51200001bca0]{connected}: State change to disconnected (X31, 5s) (context_map_sccp.c:382)
20240606070057769 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-7994758)[0x51200001bb20]{connected}: Received Event MAP_RUA_EV_CN_DISC (context_map_sccp.c:465)
20240606070057769 DHNB INFO map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-7994758)[0x51200001bb20]{connected}: Tx RUA Disconnect (context_map_rua.c:262)
20240606070057769 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-7994758)[0x51200001bb20]{connected}: State change to disrupted (X31, 5s) (context_map_rua.c:305)
20240606070057769 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-7994758)[0x51200001bb20]{disrupted}: Terminating (cause = OSMO_FSM_TERM_REGULAR) (context_map.c:202)
20240606070057769 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-7994758)[0x51200001bb20]{disrupted}: Freeing instance (context_map.c:202)
20240606070057769 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-7994758)[0x51200001bb20]{disrupted}: Deallocated (fsm.c:568)
20240606070057769 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-40)[0x51200001bca0]{disconnected}: Terminating (cause = OSMO_FSM_TERM_REGULAR) (context_map.c:206)
20240606070057769 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-40)[0x51200001bca0]{disconnected}: Freeing instance (context_map.c:206)
20240606070057769 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-40)[0x51200001bca0]{disconnected}: Deallocated (fsm.c:568)
20240606070057770 DMAIN INFO (127.0.1.1:9999 TTCN3-HNB-0) RUA-7994758 SCCP-40 msc-2 MI=TMSI-0x42800023: Deallocating (context_map.c:225)
20240606070057770 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-41)[0x5120000201a0]{connected}: Received Event MAP_SCCP_EV_RAN_LINK_LOST (context_map.c:189)
20240606070057770 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-41)[0x5120000201a0]{connected}: State change to disconnected (X31, 5s) (context_map_sccp.c:382)
20240606070057770 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-291557)[0x512000020020]{connected}: Received Event MAP_RUA_EV_CN_DISC (context_map_sccp.c:465)
20240606070057770 DHNB INFO map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-291557)[0x512000020020]{connected}: Tx RUA Disconnect (context_map_rua.c:262)
20240606070057770 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-291557)[0x512000020020]{connected}: State change to disrupted (X31, 5s) (context_map_rua.c:305)
20240606070057770 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-291557)[0x512000020020]{disrupted}: Terminating (cause = OSMO_FSM_TERM_REGULAR) (context_map.c:202)
20240606070057771 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-291557)[0x512000020020]{disrupted}: Freeing instance (context_map.c:202)
20240606070057771 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-291557)[0x512000020020]{disrupted}: Deallocated (fsm.c:568)
20240606070057771 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-41)[0x5120000201a0]{disconnected}: Terminating (cause = OSMO_FSM_TERM_REGULAR) (context_map.c:206)
20240606070057771 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-41)[0x5120000201a0]{disconnected}: Freeing instance (context_map.c:206)
20240606070057771 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-2-SCCP-41)[0x5120000201a0]{disconnected}: Deallocated (fsm.c:568)
20240606070057771 DMAIN INFO (127.0.1.1:9999 TTCN3-HNB-0) RUA-291557 SCCP-41 msc-2 MI=TMSI-0x42A98023: Deallocating (context_map.c:225)
20240606070057771 DCN DEBUG sccp_sap_up(N-PCSTATE.indication) (hnbgw_cn.c:647)
20240606070057771 DCN DEBUG N-PCSTATE ind: affected_pc=185 sp_status=INACCESSIBLE remote_sccp_status=UNAVAILABLE_UNKNOWN (hnbgw_cn.c:557)
20240606070057771 DCN NOTICE (sgsn-0) now unreachable: N-PCSTATE ind: pc=185 sp_status=INACCESSIBLE remote_sccp_status=UNAVAILABLE_UNKNOWN (hnbgw_cn.c:620)
20240606070057771 DRANAP NOTICE cnlink(sgsn-0)[0x512000005020]{DISCONNECTED}: link lost (cnlink.c:118)
20240606070057771 DCN DEBUG sccp_sap_up(N-PCSTATE.indication) (hnbgw_cn.c:647)
20240606070057771 DCN DEBUG N-PCSTATE ind: affected_pc=10 sp_status=INACCESSIBLE remote_sccp_status=UNAVAILABLE_UNKNOWN (hnbgw_cn.c:557)
20240606070057771 DCN NOTICE (sgsn-1) now unreachable: N-PCSTATE ind: pc=10 sp_status=INACCESSIBLE remote_sccp_status=UNAVAILABLE_UNKNOWN (hnbgw_cn.c:620)
20240606070057771 DRANAP NOTICE cnlink(sgsn-1)[0x512000005320]{DISCONNECTED}: link lost (cnlink.c:118)
20240606070057771 DMAIN NOTICE (127.0.1.1:9999 TTCN3-HNB-0) sctp_recvmsg(r=127.0.1.1:9999<->l=127.0.0.1:29169) = SCTP_SHUTDOWN_EVENT, closing conn (hnbgw.c:793)
20240606070057772 DMAIN INFO (disconnected TTCN3-HNB-0) Releasing HNB context (hnbgw.c:351)
20240606070057772 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-15282514)[0x5120000204a0]{connected}: Received Event MAP_RUA_EV_HNB_LINK_LOST (context_map.c:184)
20240606070057772 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-15282514)[0x5120000204a0]{connected}: State change to disrupted (X31, 5s) (context_map_rua.c:298)
20240606070057772 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-42)[0x512000020620]{wait_cc}: Received Event MAP_SCCP_EV_RAN_LINK_LOST (context_map_rua.c:319)
20240606070057832 DCN DEBUG sccp_sap_up(N-CONNECT.confirm) (hnbgw_cn.c:647)
20240606070057832 DCN DEBUG handle_cn_conn_conf() conn_id=42, addrs: called=RI=SSN_PC,PC=0.0.2,SSN=RANAP calling=RI=SSN_PC,PC=0.23.5,SSN=RANAP responding=RI=NONE (hnbgw_cn.c:483)
20240606070057832 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-42)[0x512000020620]{wait_cc}: Received Event MAP_SCCP_EV_RX_CONNECTION_CONFIRM (hnbgw_cn.c:489)
20240606070057834 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-42)[0x512000020620]{wait_cc}: State change to connected (no timeout) (context_map_sccp.c:304)
20240606070057834 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-42)[0x512000020620]{connected}: State change to disconnected (X31, 5s) (context_map_sccp.c:342)
20240606070057834 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-15282514)[0x5120000204a0]{disrupted}: Terminating (cause = OSMO_FSM_TERM_REGULAR) (context_map.c:202)
20240606070057834 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-15282514)[0x5120000204a0]{disrupted}: Freeing instance (context_map.c:202)
20240606070057834 DHNB DEBUG map_rua(127-0-1-1:9999-TTCN3-HNB-0-CS-RUA-15282514)[0x5120000204a0]{disrupted}: Deallocated (fsm.c:568)
20240606070057834 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-42)[0x512000020620]{disconnected}: Terminating (cause = OSMO_FSM_TERM_REGULAR) (context_map.c:206)
20240606070057834 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-42)[0x512000020620]{disconnected}: Freeing instance (context_map.c:206)
20240606070057834 DCN DEBUG map_sccp(127-0-1-1:9999-TTCN3-HNB-0-msc-1-SCCP-42)[0x512000020620]{disconnected}: Deallocated (fsm.c:568)
20240606070057834 DMAIN INFO (NULL) RUA-15282514 SCCP-42 msc-1 MI=IMSI-262420000000001: Deallocating (context_map.c:225)
=================================================================
==571587==ERROR: AddressSanitizer: heap-use-after-free on address 0x512000020648 at pc 0x55f8b2009974 bp 0x7fff87231280 sp 0x7fff87231278
READ of size 8 at 0x512000020648 thread T0
#0 0x55f8b2009973 in handle_rx_sccp ../../../../src/osmo-hnbgw/src/osmo-hnbgw/context_map_sccp.c:198
#1 0x55f8b200b889 in map_sccp_wait_cc_action ../../../../src/osmo-hnbgw/src/osmo-hnbgw/context_map_sccp.c:306
#2 0x7f9580db6ec6 in _osmo_fsm_inst_dispatch ../../../../src/libosmocore/src/core/fsm.c:875
#3 0x55f8b1ffe26f in _map_sccp_dispatch ../../../../src/osmo-hnbgw/src/osmo-hnbgw/context_map.c:163
#4 0x55f8b2016bcc in handle_cn_conn_conf ../../../../src/osmo-hnbgw/src/osmo-hnbgw/hnbgw_cn.c:489
#5 0x55f8b2019606 in sccp_sap_up ../../../../src/osmo-hnbgw/src/osmo-hnbgw/hnbgw_cn.c:671
#6 0x7f9582a0a6fd in sccp_user_prim_up ../../../src/libosmo-sccp/src/sccp_user.c:178
#7 0x7f9582a006ff in scu_gen_encode_and_send ../../../src/libosmo-sccp/src/sccp_scoc.c:942
#8 0x7f9582a0212e in scoc_fsm_conn_pend_out ../../../src/libosmo-sccp/src/sccp_scoc.c:1135
#9 0x7f9580db6ec6 in _osmo_fsm_inst_dispatch ../../../../src/libosmocore/src/core/fsm.c:875
#10 0x7f9582a06bf0 in sccp_scoc_rx_from_scrc ../../../src/libosmo-sccp/src/sccp_scoc.c:1857
#11 0x7f95829f43bc in scrc_rx_mtp_xfer_ind_xua ../../../src/libosmo-sccp/src/sccp_scrc.c:479
#12 0x7f9582a0acd0 in mtp_user_prim_cb ../../../src/libosmo-sccp/src/sccp_user.c:203
#13 0x7f95829a42d6 in deliver_to_mtp_user ../../../src/libosmo-sccp/src/osmo_ss7_hmrt.c:95
#14 0x7f95829a4966 in hmdt_message_for_distribution ../../../src/libosmo-sccp/src/osmo_ss7_hmrt.c:134
#15 0x7f95829a64bd in m3ua_hmdc_rx_from_l2 ../../../src/libosmo-sccp/src/osmo_ss7_hmrt.c:284
#16 0x7f95829751c4 in m3ua_rx_xfer ../../../src/libosmo-sccp/src/m3ua.c:576
#17 0x7f9582977090 in m3ua_rx_msg ../../../src/libosmo-sccp/src/m3ua.c:731
#18 0x7f958299d045 in xua_cli_read_cb ../../../src/libosmo-sccp/src/osmo_ss7_asp.c:1066
#19 0x7f9583119f03 in stream_cli_iofd_recvmsg_cb ../../../src/libosmo-netif/src/stream_cli.c:530
#20 0x7f9580e0064a in iofd_handle_recv ../../../../src/libosmocore/src/core/osmo_io.c:368
#21 0x7f9580e07f6b in iofd_poll_ofd_cb_recvmsg_sendmsg ../../../../src/libosmocore/src/core/osmo_io_poll.c:77
#22 0x7f9580e08832 in iofd_poll_ofd_cb_dispatch ../../../../src/libosmocore/src/core/osmo_io_poll.c:115
#23 0x7f9580e17775 in poll_disp_fds ../../../../src/libosmocore/src/core/select.c:419
#24 0x7f9580e17902 in _osmo_select_main ../../../../src/libosmocore/src/core/select.c:457
#25 0x7f9580e179e5 in osmo_select_main_ctx ../../../../src/libosmocore/src/core/select.c:513
#26 0x55f8b1fc1825 in main ../../../../src/osmo-hnbgw/src/osmo-hnbgw/osmo_hnbgw_main.c:364
#27 0x7f9580a42c89 (/lib/x86_64-linux-gnu/libc.so.6+0x27c89) (BuildId: 3264bbfd8d6151ee14beb5444dc47c60bc1ff1f4)
#28 0x7f9580a42d44 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x27d44) (BuildId: 3264bbfd8d6151ee14beb5444dc47c60bc1ff1f4)
#29 0x55f8b1fbf770 in _start (/usr/local/bin/osmo-hnbgw+0x133770) (BuildId: 3acb0cb6b1b55caeb26a4fa95949d003b9ed5d80)
0x512000020648 is located 136 bytes inside of 296-byte region [0x5120000205c0,0x5120000206e8)
freed by thread T0 here:
#0 0x7f95840f2868 in free ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:52
#1 0x7f95827f65e1 (/lib/x86_64-linux-gnu/libtalloc.so.2+0x45e1) (BuildId: 75c550e5dc091c77e1159c52b284f34d0c4d92cd)
#2 0x7f9580dafbc7 in osmo_fsm_inst_free ../../../../src/libosmocore/src/core/fsm.c:569
#3 0x7f9580dbb129 in _osmo_fsm_inst_term ../../../../src/libosmocore/src/core/fsm.c:957
#4 0x55f8b1fff490 in context_map_free ../../../../src/osmo-hnbgw/src/osmo-hnbgw/context_map.c:206
#5 0x55f8b200db81 in map_sccp_disconnected_onenter ../../../../src/osmo-hnbgw/src/osmo-hnbgw/context_map_sccp.c:467
#6 0x7f9580db439f in state_chg ../../../../src/libosmocore/src/core/fsm.c:697
#7 0x7f9580db44ac in _osmo_fsm_inst_state_chg_ms ../../../../src/libosmocore/src/core/fsm.c:752
#8 0x7f9580e5143b in _osmo_tdef_fsm_inst_state_chg ../../../../src/libosmocore/src/core/tdef.c:370
#9 0x55f8b200c5b4 in map_sccp_connected_onenter ../../../../src/osmo-hnbgw/src/osmo-hnbgw/context_map_sccp.c:342
#10 0x7f9580db439f in state_chg ../../../../src/libosmocore/src/core/fsm.c:697
#11 0x7f9580db4458 in _osmo_fsm_inst_state_chg ../../../../src/libosmocore/src/core/fsm.c:746
#12 0x7f9580e50ed0 in _osmo_tdef_fsm_inst_state_chg ../../../../src/libosmocore/src/core/tdef.c:344
#13 0x55f8b200b833 in map_sccp_wait_cc_action ../../../../src/osmo-hnbgw/src/osmo-hnbgw/context_map_sccp.c:304
#14 0x7f9580db6ec6 in _osmo_fsm_inst_dispatch ../../../../src/libosmocore/src/core/fsm.c:875
#15 0x55f8b1ffe26f in _map_sccp_dispatch ../../../../src/osmo-hnbgw/src/osmo-hnbgw/context_map.c:163
#16 0x55f8b2016bcc in handle_cn_conn_conf ../../../../src/osmo-hnbgw/src/osmo-hnbgw/hnbgw_cn.c:489
#17 0x55f8b2019606 in sccp_sap_up ../../../../src/osmo-hnbgw/src/osmo-hnbgw/hnbgw_cn.c:671
#18 0x7f9582a0a6fd in sccp_user_prim_up ../../../src/libosmo-sccp/src/sccp_user.c:178
#19 0x7f9582a006ff in scu_gen_encode_and_send ../../../src/libosmo-sccp/src/sccp_scoc.c:942
#20 0x7f9582a0212e in scoc_fsm_conn_pend_out ../../../src/libosmo-sccp/src/sccp_scoc.c:1135
#21 0x7f9580db6ec6 in _osmo_fsm_inst_dispatch ../../../../src/libosmocore/src/core/fsm.c:875
#22 0x7f9582a06bf0 in sccp_scoc_rx_from_scrc ../../../src/libosmo-sccp/src/sccp_scoc.c:1857
#23 0x7f95829f43bc in scrc_rx_mtp_xfer_ind_xua ../../../src/libosmo-sccp/src/sccp_scrc.c:479
#24 0x7f9582a0acd0 in mtp_user_prim_cb ../../../src/libosmo-sccp/src/sccp_user.c:203
#25 0x7f95829a42d6 in deliver_to_mtp_user ../../../src/libosmo-sccp/src/osmo_ss7_hmrt.c:95
#26 0x7f95829a4966 in hmdt_message_for_distribution ../../../src/libosmo-sccp/src/osmo_ss7_hmrt.c:134
#27 0x7f95829a64bd in m3ua_hmdc_rx_from_l2 ../../../src/libosmo-sccp/src/osmo_ss7_hmrt.c:284
#28 0x7f95829751c4 in m3ua_rx_xfer ../../../src/libosmo-sccp/src/m3ua.c:576
#29 0x7f9582977090 in m3ua_rx_msg ../../../src/libosmo-sccp/src/m3ua.c:731
previously allocated by thread T0 here:
#0 0x7f95840f3bc7 in malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:69
#1 0x7f95827f7e73 (/lib/x86_64-linux-gnu/libtalloc.so.2+0x5e73) (BuildId: 75c550e5dc091c77e1159c52b284f34d0c4d92cd)
SUMMARY: AddressSanitizer: heap-use-after-free ../../../../src/osmo-hnbgw/src/osmo-hnbgw/context_map_sccp.c:198 in handle_rx_sccp
Shadow bytes around the buggy address:
0x512000020380: 00 00 00 00 00 00 00 00 00 00 00 00 00 fa fa fa
0x512000020400: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
0x512000020480: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x512000020500: fd fd fd fd fd fd fd fd fd fd fd fd fd fa fa fa
0x512000020580: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
=>0x512000020600: fd fd fd fd fd fd fd fd fd[fd]fd fd fd fd fd fd
0x512000020680: fd fd fd fd fd fd fd fd fd fd fd fd fd fa fa fa
0x512000020700: fa fa fa fa fa fa fa fa 00 00 00 00 00 00 00 00
0x512000020780: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
0x512000020800: 00 00 00 00 00 00 00 00 00 00 00 00 00 fa fa fa
0x512000020880: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
Shadow byte legend (one shadow byte represents 8 application bytes):
Addressable: 00
Partially addressable: 01 02 03 04 05 06 07
Heap left redzone: fa
Freed heap region: fd
Stack left redzone: f1
Stack mid redzone: f2
Stack right redzone: f3
Stack after return: f5
Stack use after scope: f8
Global redzone: f9
Global init order: f6
Poisoned by user: f7
Container overflow: fc
Array cookie: ac
Intra object redzone: bb
ASan internal: fe
Left alloca redzone: ca
Right alloca redzone: cb
==571587==ABORTING
Related issues
Actions
