See <https://jenkins.osmocom.org/jenkins/job/ttcn3-hnbgw-test-asan/164/display/redirect> Changes: ------------------------------------------ [...truncated 5.42 MiB...] HNBGW_Test.sgsn0-RAN(403)@4e41ba2c10aa: f_create_expect(l3 := '4291243F1275E01FF642'O, n_connectPointCode := omit HNBGW_Test.sgsn0-RAN(403)@4e41ba2c10aa: Created Expect[1] for '4291243F1275E01FF642'O to be handled at TC_ps_rab_assignment_concurrent0(418) TC_ps_rab_assignment_concurrent-Iuh0-RUA(398)@4e41ba2c10aa: Added conn table entry 12TC_ps_rab_assignment_concurrent0(418)7360315 #0 0x5598c23203f3 (/usr/bin/osmo-hnbgw+0x1a73f3) #1 0x5598c229314f (/usr/bin/osmo-hnbgw+0x11a14f) #2 0x5598c22959b6 (/usr/bin/osmo-hnbgw+0x11c9b6) #3 0x5598c2280d0a (/usr/bin/osmo-hnbgw+0x107d0a) #4 0x7fe79d15e40b (/lib/x86_64-linux-gnu/libosmonetif.so.11+0xc140b) #5 0x7fe798fd4f75 (/lib/x86_64-linux-gnu/libosmocore.so.22+0x1d4f75) #6 0x7fe798fd54b8 in osmo_select_main_ctx (/lib/x86_64-linux-gnu/libosmocore.so.22+0x1d54b8) #7 0x5598c227b734 (/usr/bin/osmo-hnbgw+0x102734) #8 0x7fe798446249 (/lib/x86_64-linux-gnu/libc.so.6+0x27249) #9 0x7fe798446304 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x27304) #10 0x5598c227c9b0 (/usr/bin/osmo-hnbgw+0x1039b0) 0x60b0006bbbfa is located 6 bytes to the left of 100-byte region [0x60b0006bbc00,0x60b0006bbc64) allocated by thread T0 here: #0 0x7fe79d2b89cf in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:69 #1 0x7fe79d8bee3d (/lib/x86_64-linux-gnu/libtalloc.so.2+0x5e3d) SUMMARY: AddressSanitizer: heap-buffer-overflow (/usr/bin/osmo-hnbgw+0x1a73f3) Shadow bytes around the buggy address: 0x0c16800cf720: fa fa fa fa fa fa fa fa 00 00 00 00 00 00 00 00 0x0c16800cf730: 00 00 00 00 04 fa fa fa fa fa fa fa fa fa 00 00 0x0c16800cf740: 00 00 00 00 00 00 00 00 00 00 03 fa fa fa fa fa 0x0c16800cf750: fa fa fa fa 00 00 00 00 00 00 00 00 00 00 00 00 0x0c16800cf760: 03 fa fa fa fa fa fa fa fa fa 00 00 00 00 00 00 =>0x0c16800cf770: 00 00 00 00 00 00 00 03 fa fa fa fa fa fa fa[fa] 0x0c16800cf780: 00 00 00 00 00 00 00 00 00 00 00 00 04 fa fa fa 0x0c16800cf790: fa fa fa fa fa fa 00 00 00 00 00 00 00 00 00 00 0x0c16800cf7a0: 00 00 04 fa fa fa fa fa fa fa fa fa fd fd fd fd 0x0c16800cf7b0: fd fd fd fd fd fd fd fd fd fa fa fa fa fa fa fa 0x0c16800cf7c0: fa fa fd fd fd fd fd fd fd fd fd fd fd fd fd 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 ==9769==ABORTING HNBGW_Test.sgsn0-RAN(403)@4e41ba2c10aa: f_create_expect(l3 := '4B0A611896F807935387'O, n_connectPointCode := omit HNBGW_Test.sgsn0-RAN(403)@4e41ba2c10aa: Created Expect[10] for '4B0A611896F807935387'O to be handled at TC_ps_rab_assignment_concurrent0(419) TC_ps_rab_assignment_concurrent-Iuh0-RUA(398)@4e41ba2c10aa: Added conn table entry 13TC_ps_rab_assignment_concurrent0(419)11320770 20241117174653690 DLINP <0002> stream_srv.c:673 SRVCONN(asp-dyn-0,r=::1:47421<->l=::1:2905) connection closed with client 20241117174653690 DLSS7 <000c> osmo_ss7_asp.c:834 0: asp-asp-dyn-0: ss7_asp_xua_srv_conn_rx_cb(): sctp_recvmsg() returned 0 (flags=0x80) 20241117174653690 DLSS7 <000c> osmo_ss7_asp.c:772 0: asp-asp-dyn-0: xUA SRV SCTP NOTIFICATION 32769 flags=0x0 20241117174653690 DLSS7 <000c> osmo_ss7_asp.c:780 0: asp-asp-dyn-0: xUA SRV SCTP_ASSOC_CHANGE: COMM_LOST 20241117174653690 DLINP <0002> stream.c:265 asp-dyn-0 NOTIFICATION SEND_FAILED flags=0x1 20241117174653690 DLSS7 <000c> osmo_ss7_asp.c:834 0: asp-asp-dyn-0: ss7_asp_xua_srv_conn_rx_cb(): sctp_recvmsg() returned 0 (flags=0x80) 20241117174653690 DLSS7 <000c> osmo_ss7_asp.c:772 0: asp-asp-dyn-0: xUA SRV SCTP NOTIFICATION 32771 flags=0x1 20241117174653690 DLSS7 <000c> osmo_ss7_asp.c:795 0: asp-asp-dyn-0: xUA SRV SEND_FAILED 20241117174653690 DLINP <0002> stream_srv.c:670 SRVCONN(asp-dyn-0,r=::1:47421<->l=::1:2905) lost connection with client (-104) 20241117174653690 DLSS7 <000c> osmo_ss7_asp.c:834 0: asp-asp-dyn-0: ss7_asp_xua_srv_conn_rx_cb(): sctp_recvmsg() returned 0 (flags=0x0) 20241117174653690 DLSS7 <000c> osmo_ss7_asp.c:1082 asp-dyn-0: connection closed 20241117174653690 DLSS7 <000c> osmo_ss7_asp.c:1088 XUA_ASP(asp-dyn-0){ASP_ACTIVE}: Received Event SCTP-COMM_DOWN.ind 20241117174653690 DLSS7 <000c> xua_asp_fsm.c:687 XUA_ASP(asp-dyn-0){ASP_ACTIVE}: state_chg to ASP_DOWN 20241117174653690 DLSS7 <000c> xua_asp_fsm.c:368 XUA_AS(as-rkm-7){AS_ACTIVE}: Received Event ASPAS-ASP_DOWN.ind 20241117174653690 DLSS7 <000c> xua_as_fsm.c:437 XUA_AS(as-rkm-7){AS_ACTIVE}: state_chg to AS_PENDING 20241117174653690 DLSS7 <000c> xua_asp_fsm.c:119 XUA_ASP(asp-dyn-0){ASP_DOWN}: No Layer Manager, dropping M-ASP_DOWN.indication 20241117174653690 DLSS7 <000c> osmo_ss7_as.c:171 0: as-as-rkm-7: Destroying AS 20241117174653690 DLSS7 <000c> osmo_ss7_as.c:174 XUA_AS(as-rkm-7){AS_PENDING}: Terminating (cause = OSMO_FSM_TERM_REQUEST) 20241117174653690 DLSS7 <000c> osmo_ss7_as.c:174 XUA_AS(as-rkm-7){AS_PENDING}: Freeing instance 20241117174653690 DLSS7 <000c> fsm.c:568 XUA_AS(as-rkm-7){AS_PENDING}: Deallocated 20241117174653690 DLSS7 <000c> osmo_ss7_route.c:248 0: Destroying route: pc=189=0.23.5 mask=0x3fff via linkset/ASP 'as-rkm-7' 20241117174653691 DLSS7 <000c> xua_asp_fsm.c:119 XUA_ASP(asp-dyn-0){ASP_DOWN}: No Layer Manager, dropping M-SCTP_RELEASE.indication 20241117174653691 DLSS7 <000c> osmo_ss7_asp.c:581 0: asp-asp-dyn-0: Destroying ASP 20241117174653691 DLSS7 <000c> osmo_ss7_asp.c:588 XUA_ASP(asp-dyn-0){ASP_DOWN}: Terminating (cause = OSMO_FSM_TERM_REQUEST) 20241117174653691 DLSS7 <000c> osmo_ss7_asp.c:588 XUA_ASP(asp-dyn-0){ASP_DOWN}: Freeing instance 20241117174653691 DLSS7 <000c> fsm.c:568 XUA_ASP(asp-dyn-0){ASP_DOWN}: Deallocated 20241117174653691 DLSS7 <000c> osmo_ss7_asp.c:834 0: asp-virt-sgsn0-0: ss7_asp_xua_srv_conn_rx_cb(): sctp_recvmsg() returned 0 (flags=0x0) 20241117174653691 DLM3UA <000f> m3ua.c:749 0: asp-virt-sgsn0-0: Received M3UA Message (XFER:DATA) 20241117174653691 DLM3UA <000f> m3ua.c:566 0: asp-virt-sgsn0-0: m3ua_rx_xfer 20241117174653691 DLM3UA <000f> m3ua.c:601 0: asp-virt-sgsn0-0: m3ua_rx_xfer(): M3UA data header: opc=185=0.23.1 dpc=189=0.23.5 20241117174653691 DLSS7 <000c> osmo_ss7_hmrt.c:292 m3ua_hmdc_rx_from_l2(): dpc=189=0.23.5 not local, message is for routing 20241117174653691 DLSS7 <000c> osmo_ss7_hmrt.c:272 MTP-TRANSFER.req for DPC 189: no route! 20241117174653691 DLSS7 <000c> osmo_ss7_asp.c:834 0: asp-virt-sgsn0-0: ss7_asp_xua_srv_conn_rx_cb(): sctp_recvmsg() returned 0 (flags=0x0) 20241117174653691 DLM3UA <000f> m3ua.c:749 0: asp-virt-sgsn0-0: Received M3UA Message (XFER:DATA) 20241117174653691 DLM3UA <000f> m3ua.c:566 0: asp-virt-sgsn0-0: m3ua_rx_xfer 20241117174653691 DLM3UA <000f> m3ua.c:601 0: asp-virt-sgsn0-0: m3ua_rx_xfer(): M3UA data header: opc=185=0.23.1 dpc=189=0.23.5 20241117174653691 DLSS7 <000c> osmo_ss7_hmrt.c:292 m3ua_hmdc_rx_from_l2(): dpc=189=0.23.5 not local, message is for routing 20241117174653691 DLSS7 <000c> osmo_ss7_hmrt.c:272 MTP-TRANSFER.req for DPC 189: no route! 20241117174653691 DLSS7 <000c> osmo_ss7_asp.c:834 0: asp-virt-sgsn0-0: ss7_asp_xua_srv_conn_rx_cb(): sctp_recvmsg() returned 0 (flags=0x0) 20241117174653691 DLM3UA <000f> m3ua.c:749 0: asp-virt-sgsn0-0: Received M3UA Message (XFER:DATA) 20241117174653691 DLM3UA <000f> m3ua.c:566 0: asp-virt-sgsn0-0: m3ua_rx_xfer 20241117174653691 DLM3UA <000f> m3ua.c:601 0: asp-virt-sgsn0-0: m3ua_rx_xfer(): M3UA data header: opc=185=0.23.1 dpc=189=0.23.5 20241117174653691 DLSS7 <000c> osmo_ss7_hmrt.c:292 m3ua_hmdc_rx_from_l2(): dpc=189=0.23.5 not local, message is for routing 20241117174653691 DLSS7 <000c> osmo_ss7_hmrt.c:272 MTP-TRANSFER.req for DPC 189: no route! TC_ps_rab_assignment_concurrent-Iuh0(397)@4e41ba2c10aa: Iuh: Closed IPA-CTRL-CLI-IPA(395)@4e41ba2c10aa: IPA: Closed TC_ps_rab_assignment_concurrent-Iuh0(397)@4e41ba2c10aa: Final verdict of PTC: none IPA-CTRL-CLI-IPA(395)@4e41ba2c10aa: Final verdict of PTC: none HNBGW_Test.sgsn0-RAN(403)@4e41ba2c10aa: f_create_expect(l3 := 'F64D2A0EFC2A7E846579'O, n_connectPointCode := omit HNBGW_Test.sgsn0-RAN(403)@4e41ba2c10aa: Created Expect[11] for 'F64D2A0EFC2A7E846579'O to be handled at TC_ps_rab_assignment_concurrent0(420) TC_ps_rab_assignment_concurrent-Iuh0-RUA(398)@4e41ba2c10aa: Added conn table entry 14TC_ps_rab_assignment_concurrent0(420)1085915 TC_ps_rab_assignment_concurrent-Iuh0-RUA(398)@4e41ba2c10aa: Dynamic test case error: Port RUA has neither connections nor mappings. Message cannot be sent on it. TC_ps_rab_assignment_concurrent-Iuh0-RUA(398)@4e41ba2c10aa: setverdict(error): none -> error TC_ps_rab_assignment_concurrent-Iuh0-RUA(398)@4e41ba2c10aa: Final verdict of PTC: error HNBGW_Test.sgsn0-RAN(403)@4e41ba2c10aa: f_create_expect(l3 := '850086301D08F5E90E16'O, n_connectPointCode := omit HNBGW_Test.sgsn0-RAN(403)@4e41ba2c10aa: Created Expect[12] for '850086301D08F5E90E16'O to be handled at TC_ps_rab_assignment_concurrent0(421) TC_ps_rab_assignment_concurrent0(421)@4e41ba2c10aa: Dynamic test case error: Port RUA has neither connections nor mappings. Message cannot be sent on it. TC_ps_rab_assignment_concurrent0(421)@4e41ba2c10aa: setverdict(error): none -> error TC_ps_rab_assignment_concurrent0(421)@4e41ba2c10aa: Final verdict of PTC: error [testenv][generic] Looking for a coredump [testenv][generic] coredumpctl is not available, won't try to get coredump [testenv][generic] hnbgw crashed during HNBGW_Tests.TC_ps_rab_assignment_concurrent! [testenv][generic] Waiting until test has stopped... TC_ps_rab_assignment_concurrent0(406)@4e41ba2c10aa: setverdict(fail): pass -> fail reason: "Timeout waiting for Iuh { initiatingMessage := { procedureCode := 0, criticality := reject (0), value_ := { rAB_AssignmentRequest := { protocolIEs := { { id := 54, criticality := ignore (1), value_ := { rAB_SetupOrModifyList := { { { id := 53, firstCriticality := reject (0), firstValue := { rAB_SetupOrModifyItemFirst := { rAB_ID := '00010111'B, nAS_SynchronisationIndicator := omit, rAB_Parameters := { trafficClass := conversational (0), rAB_AsymmetryIndicator := symmetric_bidirectional (0), maxBitrate := { 12200 }, guaranteedBitRate := { 12200 }, deliveryOrder := delivery_order_requested (0), maxSDU_Size := 244, sDU_Parameters := { { sDU_ErrorRatio := { mantissa := 1, exponent := 5, iE_Extensions := omit }, residualBitErrorRatio := { mantissa := 1, exponent := 6, iE_Extensions := omit }, deliveryOfErroneousSDU := yes (0), sDU_FormatInformationParameters := { { subflowSDU_Size := 81, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit }, { subflowSDU_Size := 39, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit } }, iE_Extensions := omit }, { sDU_ErrorRatio := omit, residualBitErrorRatio := { mantissa := 1, exponent := 3, iE_Extensions := omit }, deliveryOfErroneousSDU := no_error_detection_consideration (2), sDU_FormatInformationParameters := { { subflowSDU_Size := 103, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit }, { subflowSDU_Size := 0, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit } }, iE_Extensions := omit }, { sDU_ErrorRatio := omit, residualBitErrorRatio := { mantissa := 5, exponent := 3, iE_Extensions := omit }, deliveryOfErroneousSDU := no_error_detection_consideration (2), sDU_FormatInformationParameters := { { subflowSDU_Size := 60, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit }, { subflowSDU_Size := 0, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit } }, iE_Extensions := omit } }, transferDelay := 80, trafficHandlingPriority := omit, allocationOrRetentionPriority := { priorityLevel := 15, pre_emptionCapability := shall_not_trigger_pre_emption (0), pre_emptionVulnerability := pre_emptable (1), queuingAllowed := queueing_not_allowed (0), iE_Extensions := omit }, sourceStatisticsDescriptor := omit, relocationRequirement := omit, iE_Extensions := omit }, userPlaneInformation := { userPlaneMode := support_mode_for_predefined_SDU_sizes (1), uP_ModeVersions := '0000000000000010'B, iE_Extensions := omit }, transportLayerInformation := { transportLayerAddress := '0011010100000000000000010111111100000000000000000000000100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000'B, iuTransportAssociation := { gTP_TEI := '10101010'O }, iE_Extensions := omit }, service_Handover := omit, iE_Extensions := omit } }, secondCriticality := ignore (1), secondValue := { rAB_SetupOrModifyItemSecond := { pDP_TypeInformation := omit, dataVolumeReportingIndication := omit, dl_GTP_PDU_SequenceNumber := omit, ul_GTP_PDU_SequenceNumber := omit, dl_N_PDU_SequenceNumber := omit, ul_N_PDU_SequenceNumber := omit, iE_Extensions := omit } } } } } } } }, protocolExtensions := omit } } } }", new component reason: "Timeout waiting for Iuh { initiatingMessage := { procedureCode := 0, criticality := reject (0), value_ := { rAB_AssignmentRequest := { protocolIEs := { { id := 54, criticality := ignore (1), value_ := { rAB_SetupOrModifyList := { { { id := 53, firstCriticality := reject (0), firstValue := { rAB_SetupOrModifyItemFirst := { rAB_ID := '00010111'B, nAS_SynchronisationIndicator := omit, rAB_Parameters := { trafficClass := conversational (0), rAB_AsymmetryIndicator := symmetric_bidirectional (0), maxBitrate := { 12200 }, guaranteedBitRate := { 12200 }, deliveryOrder := delivery_order_requested (0), maxSDU_Size := 244, sDU_Parameters := { { sDU_ErrorRatio := { mantissa := 1, exponent := 5, iE_Extensions := omit }, residualBitErrorRatio := { mantissa := 1, exponent := 6, iE_Extensions := omit }, deliveryOfErroneousSDU := yes (0), sDU_FormatInformationParameters := { { subflowSDU_Size := 81, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit }, { subflowSDU_Size := 39, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit } }, iE_Extensions := omit }, { sDU_ErrorRatio := omit, residualBitErrorRatio := { mantissa := 1, exponent := 3, iE_Extensions := omit }, deliveryOfErroneousSDU := no_error_detection_consideration (2), sDU_FormatInformationParameters := { { subflowSDU_Size := 103, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit }, { subflowSDU_Size := 0, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit } }, iE_Extensions := omit }, { sDU_ErrorRatio := omit, residualBitErrorRatio := { mantissa := 5, exponent := 3, iE_Extensions := omit }, deliveryOfErroneousSDU := no_error_detection_consideration (2), sDU_FormatInformationParameters := { { subflowSDU_Size := 60, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit }, { subflowSDU_Size := 0, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit } }, iE_Extensions := omit } }, transferDelay := 80, trafficHandlingPriority := omit, allocationOrRetentionPriority := { priorityLevel := 15, pre_emptionCapability := shall_not_trigger_pre_emption (0), pre_emptionVulnerability := pre_emptable (1), queuingAllowed := queueing_not_allowed (0), iE_Extensions := omit }, sourceStatisticsDescriptor := omit, relocationRequirement := omit, iE_Extensions := omit }, userPlaneInformation := { userPlaneMode := support_mode_for_predefined_SDU_sizes (1), uP_ModeVersions := '0000000000000010'B, iE_Extensions := omit }, transportLayerInformation := { transportLayerAddress := '0011010100000000000000010111111100000000000000000000000100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000'B, iuTransportAssociation := { gTP_TEI := '10101010'O }, iE_Extensions := omit }, service_Handover := omit, iE_Extensions := omit } }, secondCriticality := ignore (1), secondValue := { rAB_SetupOrModifyItemSecond := { pDP_TypeInformation := omit, dataVolumeReportingIndication := omit, dl_GTP_PDU_SequenceNumber := omit, ul_GTP_PDU_SequenceNumber := omit, dl_N_PDU_SequenceNumber := omit, ul_N_PDU_SequenceNumber := omit, iE_Extensions := omit } } } } } } } }, protocolExtensions := omit } } } }" MC@4e41ba2c10aa: Test Component 406 has requested to stop MTC. Terminating current testcase execution. HNBGW_Test.msc0-RAN(400)@4e41ba2c10aa: Final verdict of PTC: none 20241117174658451 DLINP <0002> stream.c:265 virt-msc0-0 NOTIFICATION SHUTDOWN_EVENT flags=0x0 20241117174658451 DLSS7 <000c> osmo_ss7_asp.c:834 0: asp-virt-msc0-0: ss7_asp_xua_srv_conn_rx_cb(): sctp_recvmsg() returned 0 (flags=0x80) 20241117174658451 DLSS7 <000c> osmo_ss7_asp.c:772 0: asp-virt-msc0-0: xUA SRV SCTP NOTIFICATION 32773 flags=0x0 20241117174658451 DLSS7 <000c> osmo_ss7_asp.c:795 0: asp-virt-msc0-0: xUA SRV SHUTDOWN_EVENT 20241117174658451 DLINP <0002> stream.c:265 virt-msc0-0 NOTIFICATION ASSOC_CHANGE flags=0x0 SHUTDOWN_COMP 20241117174658451 DLSS7 <000c> osmo_ss7_asp.c:834 0: asp-virt-msc0-0: ss7_asp_xua_srv_conn_rx_cb(): sctp_recvmsg() returned 0 (flags=0x80) 20241117174658451 DLSS7 <000c> osmo_ss7_asp.c:772 0: asp-virt-msc0-0: xUA SRV SCTP NOTIFICATION 32769 flags=0x0 20241117174658451 DLSS7 <000c> osmo_ss7_asp.c:780 0: asp-virt-msc0-0: xUA SRV SCTP_ASSOC_CHANGE: SHUTDOWN_COMP HNBGW_Test.msc0-SCCP(399)@4e41ba2c10aa: Final verdict of PTC: none 20241117174658451 DLINP <0002> stream_srv.c:673 SRVCONN(virt-msc0-0,r=::ffff:127.0.0.1:23905<->l=::ffff:127.0.0.1:2905) connection closed with client 20241117174658451 DLSS7 <000c> osmo_ss7_asp.c:834 0: asp-virt-msc0-0: ss7_asp_xua_srv_conn_rx_cb(): sctp_recvmsg() returned 0 (flags=0x0) 20241117174658451 DLSS7 <000c> osmo_ss7_asp.c:1082 virt-msc0-0: connection closed 20241117174658451 DLSS7 <000c> osmo_ss7_asp.c:1088 XUA_ASP(virt-msc0-0){ASP_ACTIVE}: Received Event SCTP-COMM_DOWN.ind 20241117174658452 DLSS7 <000c> xua_asp_fsm.c:687 XUA_ASP(virt-msc0-0){ASP_ACTIVE}: state_chg to ASP_DOWN 20241117174658452 DLSS7 <000c> xua_asp_fsm.c:368 XUA_AS(virt-msc0){AS_ACTIVE}: Received Event ASPAS-ASP_DOWN.ind 20241117174658452 DLSS7 <000c> xua_as_fsm.c:437 XUA_AS(virt-msc0){AS_ACTIVE}: state_chg to AS_PENDING 20241117174658452 DLSS7 <000c> xua_asp_fsm.c:119 XUA_ASP(virt-msc0-0){ASP_DOWN}: No Layer Manager, dropping M-ASP_DOWN.indication 20241117174658452 DLSS7 <000c> xua_asp_fsm.c:119 XUA_ASP(virt-msc0-0){ASP_DOWN}: No Layer Manager, dropping M-SCTP_RELEASE.indication 20241117174658452 DLINP <0002> stream.c:265 virt-sgsn0-0 NOTIFICATION SHUTDOWN_EVENT flags=0x0 20241117174658452 DLSS7 <000c> osmo_ss7_asp.c:834 0: asp-virt-sgsn0-0: ss7_asp_xua_srv_conn_rx_cb(): sctp_recvmsg() returned 0 (flags=0x80) 20241117174658452 DLSS7 <000c> osmo_ss7_asp.c:772 0: asp-virt-sgsn0-0: xUA SRV SCTP NOTIFICATION 32773 flags=0x0 20241117174658452 DLSS7 <000c> osmo_ss7_asp.c:795 0: asp-virt-sgsn0-0: xUA SRV SHUTDOWN_EVENT 20241117174658452 DLINP <0002> stream_srv.c:647 SRVCONN(virt-sgsn0-0,r=::ffff:127.0.0.1:23906<->l=::ffff:127.0.0.1:2905) error to send: Broken pipe 20241117174658452 DLINP <0002> stream.c:265 virt-sgsn0-0 NOTIFICATION ASSOC_CHANGE flags=0x0 SHUTDOWN_COMP 20241117174658452 DLSS7 <000c> osmo_ss7_asp.c:834 0: asp-virt-sgsn0-0: ss7_asp_xua_srv_conn_rx_cb(): sctp_recvmsg() returned 0 (flags=0x80) 20241117174658452 DLSS7 <000c> osmo_ss7_asp.c:772 0: asp-virt-sgsn0-0: xUA SRV SCTP NOTIFICATION 32769 flags=0x0 20241117174658452 DLSS7 <000c> osmo_ss7_asp.c:780 0: asp-virt-sgsn0-0: xUA SRV SCTP_ASSOC_CHANGE: SHUTDOWN_COMP 20241117174658452 DLINP <0002> stream_srv.c:673 SRVCONN(virt-sgsn0-0,r=::ffff:127.0.0.1:23906<->l=::ffff:127.0.0.1:2905) connection closed with client 20241117174658452 DLSS7 <000c> osmo_ss7_asp.c:834 0: asp-virt-sgsn0-0: ss7_asp_xua_srv_conn_rx_cb(): sctp_recvmsg() returned 0 (flags=0x0) 20241117174658452 DLSS7 <000c> osmo_ss7_asp.c:1082 virt-sgsn0-0: connection closed 20241117174658452 DLSS7 <000c> osmo_ss7_asp.c:1088 XUA_ASP(virt-sgsn0-0){ASP_ACTIVE}: Received Event SCTP-COMM_DOWN.ind 20241117174658452 DLSS7 <000c> xua_asp_fsm.c:687 XUA_ASP(virt-sgsn0-0){ASP_ACTIVE}: state_chg to ASP_DOWN 20241117174658452 DLSS7 <000c> xua_asp_fsm.c:368 XUA_AS(virt-sgsn0){AS_ACTIVE}: Received Event ASPAS-ASP_DOWN.ind 20241117174658452 DLSS7 <000c> xua_as_fsm.c:437 XUA_AS(virt-sgsn0){AS_ACTIVE}: state_chg to AS_PENDING 20241117174658452 DLSS7 <000c> xua_asp_fsm.c:119 XUA_ASP(virt-sgsn0-0){ASP_DOWN}: No Layer Manager, dropping M-ASP_DOWN.indication 20241117174658452 DLSS7 <000c> xua_asp_fsm.c:119 XUA_ASP(virt-sgsn0-0){ASP_DOWN}: No Layer Manager, dropping M-SCTP_RELEASE.indication HNBGW_Test.msc0-M3UA(401)@4e41ba2c10aa: Final verdict of PTC: none HNBGW_Test.sgsn0-M3UA(404)@4e41ba2c10aa: Final verdict of PTC: none HNBGW_Test.sgsn0-SCCP(402)@4e41ba2c10aa: Final verdict of PTC: none TC_ps_rab_assignment_concurrent0(406)@4e41ba2c10aa: Final verdict of PTC: fail reason: "Timeout waiting for Iuh { initiatingMessage := { procedureCode := 0, criticality := reject (0), value_ := { rAB_AssignmentRequest := { protocolIEs := { { id := 54, criticality := ignore (1), value_ := { rAB_SetupOrModifyList := { { { id := 53, firstCriticality := reject (0), firstValue := { rAB_SetupOrModifyItemFirst := { rAB_ID := '00010111'B, nAS_SynchronisationIndicator := omit, rAB_Parameters := { trafficClass := conversational (0), rAB_AsymmetryIndicator := symmetric_bidirectional (0), maxBitrate := { 12200 }, guaranteedBitRate := { 12200 }, deliveryOrder := delivery_order_requested (0), maxSDU_Size := 244, sDU_Parameters := { { sDU_ErrorRatio := { mantissa := 1, exponent := 5, iE_Extensions := omit }, residualBitErrorRatio := { mantissa := 1, exponent := 6, iE_Extensions := omit }, deliveryOfErroneousSDU := yes (0), sDU_FormatInformationParameters := { { subflowSDU_Size := 81, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit }, { subflowSDU_Size := 39, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit } }, iE_Extensions := omit }, { sDU_ErrorRatio := omit, residualBitErrorRatio := { mantissa := 1, exponent := 3, iE_Extensions := omit }, deliveryOfErroneousSDU := no_error_detection_consideration (2), sDU_FormatInformationParameters := { { subflowSDU_Size := 103, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit }, { subflowSDU_Size := 0, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit } }, iE_Extensions := omit }, { sDU_ErrorRatio := omit, residualBitErrorRatio := { mantissa := 5, exponent := 3, iE_Extensions := omit }, deliveryOfErroneousSDU := no_error_detection_consideration (2), sDU_FormatInformationParameters := { { subflowSDU_Size := 60, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit }, { subflowSDU_Size := 0, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit } }, iE_Extensions := omit } }, transferDelay := 80, trafficHandlingPriority := omit, allocationOrRetentionPriority := { priorityLevel := 15, pre_emptionCapability := shall_not_trigger_pre_emption (0), pre_emptionVulnerability := pre_emptable (1), queuingAllowed := queueing_not_allowed (0), iE_Extensions := omit }, sourceStatisticsDescriptor := omit, relocationRequirement := omit, iE_Extensions := omit }, userPlaneInformation := { userPlaneMode := support_mode_for_predefined_SDU_sizes (1), uP_ModeVersions := '0000000000000010'B, iE_Extensions := omit }, transportLayerInformation := { transportLayerAddress := '0011010100000000000000010111111100000000000000000000000100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000'B, iuTransportAssociation := { gTP_TEI := '10101010'O }, iE_Extensions := omit }, service_Handover := omit, iE_Extensions := omit } }, secondCriticality := ignore (1), secondValue := { rAB_SetupOrModifyItemSecond := { pDP_TypeInformation := omit, dataVolumeReportingIndication := omit, dl_GTP_PDU_SequenceNumber := omit, ul_GTP_PDU_SequenceNumber := omit, dl_N_PDU_SequenceNumber := omit, ul_N_PDU_SequenceNumber := omit, iE_Extensions := omit } } } } } } } }, protocolExtensions := omit } } } }" TC_ps_rab_assignment_concurrent0(418)@4e41ba2c10aa: Final verdict of PTC: none VirtHNBGW-STATS(394)@4e41ba2c10aa: Final verdict of PTC: none TC_ps_rab_assignment_concurrent0(408)@4e41ba2c10aa: Final verdict of PTC: pass TC_ps_rab_assignment_concurrent0(411)@4e41ba2c10aa: Final verdict of PTC: none TC_ps_rab_assignment_concurrent0(407)@4e41ba2c10aa: Final verdict of PTC: pass TC_ps_rab_assignment_concurrent0(416)@4e41ba2c10aa: Final verdict of PTC: none TC_ps_rab_assignment_concurrent0(414)@4e41ba2c10aa: Final verdict of PTC: none TC_ps_rab_assignment_concurrent0(420)@4e41ba2c10aa: Final verdict of PTC: none TC_ps_rab_assignment_concurrent0(413)@4e41ba2c10aa: Final verdict of PTC: none TC_ps_rab_assignment_concurrent0(419)@4e41ba2c10aa: Final verdict of PTC: none TC_ps_rab_assignment_concurrent0(417)@4e41ba2c10aa: Final verdict of PTC: none TC_ps_rab_assignment_concurrent0(415)@4e41ba2c10aa: Final verdict of PTC: none TC_ps_rab_assignment_concurrent0(410)@4e41ba2c10aa: Final verdict of PTC: none TC_ps_rab_assignment_concurrent0(409)@4e41ba2c10aa: Final verdict of PTC: none TC_ps_rab_assignment_concurrent0(412)@4e41ba2c10aa: Final verdict of PTC: none MutexDispCT-TC_ps_rab_assignment_concurrent(393)@4e41ba2c10aa: Final verdict of PTC: none HNBGW_Test.sgsn0-RAN(403)@4e41ba2c10aa: Final verdict of PTC: none HNBGW-PFCP(396)@4e41ba2c10aa: Final verdict of PTC: none HNBGW-MGCP(405)@4e41ba2c10aa: Final verdict of PTC: none MTC@4e41ba2c10aa: Setting final verdict of the test case. MTC@4e41ba2c10aa: Local verdict of MTC: pass MTC@4e41ba2c10aa: Local verdict of PTC MutexDispCT-TC_ps_rab_assignment_concurrent(393): none (pass -> pass) MTC@4e41ba2c10aa: Local verdict of PTC VirtHNBGW-STATS(394): none (pass -> pass) MTC@4e41ba2c10aa: Local verdict of PTC IPA-CTRL-CLI-IPA(395): none (pass -> pass) MTC@4e41ba2c10aa: Local verdict of PTC HNBGW-PFCP(396): none (pass -> pass) MTC@4e41ba2c10aa: Local verdict of PTC TC_ps_rab_assignment_concurrent-Iuh0(397): none (pass -> pass) MTC@4e41ba2c10aa: Local verdict of PTC TC_ps_rab_assignment_concurrent-Iuh0-RUA(398): error (pass -> error) MTC@4e41ba2c10aa: Local verdict of PTC HNBGW_Test.msc0-SCCP(399): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC HNBGW_Test.msc0-RAN(400): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC HNBGW_Test.msc0-M3UA(401): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC HNBGW_Test.sgsn0-SCCP(402): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC HNBGW_Test.sgsn0-RAN(403): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC HNBGW_Test.sgsn0-M3UA(404): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC HNBGW-MGCP(405): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC TC_ps_rab_assignment_concurrent0(406): fail (error -> error) reason: "Timeout waiting for Iuh { initiatingMessage := { procedureCode := 0, criticality := reject (0), value_ := { rAB_AssignmentRequest := { protocolIEs := { { id := 54, criticality := ignore (1), value_ := { rAB_SetupOrModifyList := { { { id := 53, firstCriticality := reject (0), firstValue := { rAB_SetupOrModifyItemFirst := { rAB_ID := '00010111'B, nAS_SynchronisationIndicator := omit, rAB_Parameters := { trafficClass := conversational (0), rAB_AsymmetryIndicator := symmetric_bidirectional (0), maxBitrate := { 12200 }, guaranteedBitRate := { 12200 }, deliveryOrder := delivery_order_requested (0), maxSDU_Size := 244, sDU_Parameters := { { sDU_ErrorRatio := { mantissa := 1, exponent := 5, iE_Extensions := omit }, residualBitErrorRatio := { mantissa := 1, exponent := 6, iE_Extensions := omit }, deliveryOfErroneousSDU := yes (0), sDU_FormatInformationParameters := { { subflowSDU_Size := 81, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit }, { subflowSDU_Size := 39, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit } }, iE_Extensions := omit }, { sDU_ErrorRatio := omit, residualBitErrorRatio := { mantissa := 1, exponent := 3, iE_Extensions := omit }, deliveryOfErroneousSDU := no_error_detection_consideration (2), sDU_FormatInformationParameters := { { subflowSDU_Size := 103, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit }, { subflowSDU_Size := 0, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit } }, iE_Extensions := omit }, { sDU_ErrorRatio := omit, residualBitErrorRatio := { mantissa := 5, exponent := 3, iE_Extensions := omit }, deliveryOfErroneousSDU := no_error_detection_consideration (2), sDU_FormatInformationParameters := { { subflowSDU_Size := 60, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit }, { subflowSDU_Size := 0, rAB_SubflowCombinationBitRate := omit, iE_Extensions := omit } }, iE_Extensions := omit } }, transferDelay := 80, trafficHandlingPriority := omit, allocationOrRetentionPriority := { priorityLevel := 15, pre_emptionCapability := shall_not_trigger_pre_emption (0), pre_emptionVulnerability := pre_emptable (1), queuingAllowed := queueing_not_allowed (0), iE_Extensions := omit }, sourceStatisticsDescriptor := omit, relocationRequirement := omit, iE_Extensions := omit }, userPlaneInformation := { userPlaneMode := support_mode_for_predefined_SDU_sizes (1), uP_ModeVersions := '0000000000000010'B, iE_Extensions := omit }, transportLayerInformation := { transportLayerAddress := '0011010100000000000000010111111100000000000000000000000100000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000'B, iuTransportAssociation := { gTP_TEI := '10101010'O }, iE_Extensions := omit }, service_Handover := omit, iE_Extensions := omit } }, secondCriticality := ignore (1), secondValue := { rAB_SetupOrModifyItemSecond := { pDP_TypeInformation := omit, dataVolumeReportingIndication := omit, dl_GTP_PDU_SequenceNumber := omit, ul_GTP_PDU_SequenceNumber := omit, dl_N_PDU_SequenceNumber := omit, ul_N_PDU_SequenceNumber := omit, iE_Extensions := omit } } } } } } } }, protocolExtensions := omit } } } }" MTC@4e41ba2c10aa: Local verdict of PTC TC_ps_rab_assignment_concurrent0(407): pass (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC TC_ps_rab_assignment_concurrent0(408): pass (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC TC_ps_rab_assignment_concurrent0(409): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC TC_ps_rab_assignment_concurrent0(410): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC TC_ps_rab_assignment_concurrent0(411): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC TC_ps_rab_assignment_concurrent0(412): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC TC_ps_rab_assignment_concurrent0(413): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC TC_ps_rab_assignment_concurrent0(414): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC TC_ps_rab_assignment_concurrent0(415): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC TC_ps_rab_assignment_concurrent0(416): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC TC_ps_rab_assignment_concurrent0(417): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC TC_ps_rab_assignment_concurrent0(418): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC TC_ps_rab_assignment_concurrent0(419): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC TC_ps_rab_assignment_concurrent0(420): none (error -> error) MTC@4e41ba2c10aa: Local verdict of PTC TC_ps_rab_assignment_concurrent0(421): error (error -> error) MTC@4e41ba2c10aa: Test case TC_ps_rab_assignment_concurrent finished. Verdict: error MTC@4e41ba2c10aa: Starting external command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-hnbgw-test-asan/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh> HNBGW_Tests.TC_ps_rab_assignment_concurrent error'. Sun Nov 17 17:46:58 UTC 2024 ------ HNBGW_Tests.TC_ps_rab_assignment_concurrent error ------ Saving talloc report from 127.0.0.1:4261 to HNBGW_Tests.TC_ps_rab_assignment_concurrent.talloc 20241117174700453 DLSS7 <000c> xua_as_fsm.c:323 XUA_AS(virt-sgsn0){AS_PENDING}: Received Event AS-T_REC_EXPD.ind 20241117174700453 DLSS7 <000c> xua_as_fsm.c:479 XUA_AS(virt-sgsn0){AS_PENDING}: T(r) expired; dropping queued messages 20241117174700453 DLSS7 <000c> xua_as_fsm.c:485 XUA_AS(virt-sgsn0){AS_PENDING}: state_chg to AS_DOWN 20241117174700453 DLSS7 <000c> xua_as_fsm.c:323 XUA_AS(virt-msc0){AS_PENDING}: Received Event AS-T_REC_EXPD.ind 20241117174700453 DLSS7 <000c> xua_as_fsm.c:479 XUA_AS(virt-msc0){AS_PENDING}: T(r) expired; dropping queued messages 20241117174700453 DLSS7 <000c> xua_as_fsm.c:485 XUA_AS(virt-msc0){AS_PENDING}: state_chg to AS_DOWN Traceback (most recent call last): File "/usr/local/lib/python3.11/dist-packages/osmopy/osmo_interact/common.py", line 420, in main_run_commands interact.connect() File "/usr/local/lib/python3.11/dist-packages/osmopy/osmo_interact/vty.py", line 84, in connect super().connect() File "/usr/local/lib/python3.11/dist-packages/osmopy/osmo_interact/common.py", line 88, in connect self.socket.connect((self.host, int(self.port))) ConnectionRefusedError: [Errno 111] Connection refused Waiting for packet dumper to finish... 0 (prev_count=-1, count=317372) Waiting for packet dumper to finish... 1 (prev_count=317372, count=318744) MTC@4e41ba2c10aa: External command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-hnbgw-test-asan/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh> HNBGW_Tests.TC_ps_rab_assignment_concurrent error' was executed successfully (exit status: 0). MTC@4e41ba2c10aa: Starting external command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-hnbgw-test-asan/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh> HNBGW_Tests.TC_mscpool_L3Compl_on_1_cnlink'. ------ HNBGW_Tests.TC_mscpool_L3Compl_on_1_cnlink ------ Sun Nov 17 17:47:03 UTC 2024 /usr/bin/dumpcap -q -s 1520 -n -i any -w "<https://jenkins.osmocom.org/jenkins/job/ttcn3-hnbgw-test-asan/164/artifact/logs/generic/testsuite/HNBGW_Tests.TC_mscpool_L3Compl_on_1_cnlink.pcap"> ><https://jenkins.osmocom.org/jenkins/job/ttcn3-hnbgw-test-asan/164/artifact/logs/generic/testsuite/HNBGW_Tests.TC_mscpool_L3Compl_on_1_cnlink.pcap.stdout> 2>/tmp/cmderr & Waiting for packet dumper to start... 0 [testenv][generic] Stopping podman container [testenv][generic] + ['podman', 'kill', 'testenv-hnbgw-all-osmocom-nightly-asan-20241117-1743-b3d84c35-0'] 4e41ba2c10aa3ca928ab058f543312ff31924595b7f04ed7393b332626a88ab9 [testenv][generic] Stopping testsuite (3061775) [testenv] feed_watchdog_loop: podman container has stopped [testenv][generic] Logs saved to: https://jenkins.osmocom.org/jenkins/job/ttcn3-hnbgw-test-asan/164/artifact/…  Build step 'Execute shell' marked build as failure Recording test results [Checks API] No suitable checks publisher found.