Build failed in Jenkins: ttcn3-sgsn-test-io_uring #165

See <https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/165/display/redirect?page=changes> Changes: [lynxis] SGSN_Tests: add paging a whole routing area with multiple cells [lynxis] SGSN_Tests: remove unused variable d [lynxis] SGSN_Tests_NS: NS related tests: use the shutdown helper [lynxis] SGSN_Tests_NS: TC_NS_connect_alive: set missing verdict ------------------------------------------ [...truncated 1.25 MB...] MTC@a6473498aab6: Local verdict of PTC -NSVCI98-provIP(391): none (none -> none) MTC@a6473498aab6: Local verdict of PTC TC_hlr_location_cancel_request_withdraw-BVCI210(392): none (none -> none) MTC@a6473498aab6: Local verdict of PTC -NSVCI98(393): none (none -> none) MTC@a6473498aab6: Local verdict of PTC SGSN_Test-Gb2-NS2(394): none (none -> none) MTC@a6473498aab6: Local verdict of PTC SGSN_Test-Gb2-BSSGP2(395): none (none -> none) MTC@a6473498aab6: Local verdict of PTC -NSVCI99-provIP(396): none (none -> none) MTC@a6473498aab6: Local verdict of PTC TC_hlr_location_cancel_request_withdraw-BVCI220(397): none (none -> none) MTC@a6473498aab6: Local verdict of PTC -NSVCI99(398): none (none -> none) MTC@a6473498aab6: Local verdict of PTC SGSN_Test-GSUP-IPA(399): none (none -> none) MTC@a6473498aab6: Local verdict of PTC SGSN_Test-GSUP(400): none (none -> none) MTC@a6473498aab6: Local verdict of PTC SGSN_Test-GGSN_GTP(401): none (none -> none) MTC@a6473498aab6: Local verdict of PTC TC_hlr_location_cancel_request_withdraw(402): pass (none -> pass) MTC@a6473498aab6: Test case TC_hlr_location_cancel_request_withdraw finished. Verdict: pass MTC@a6473498aab6: Starting external command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh> SGSN_Tests.TC_hlr_location_cancel_request_withdraw pass'. Fri Aug 16 12:03:19 UTC 2024 ====== SGSN_Tests.TC_hlr_location_cancel_request_withdraw pass ====== Waiting for packet dumper to finish... 0 (prev_count=-1, count=44100) 20240816120320350 DLGSUP NOTICE GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74) 20240816120320350 DLGSUP INFO GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151) Waiting for packet dumper to finish... 1 (prev_count=44100, count=93200) 20240816120321351 DLGSUP NOTICE GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74) 20240816120321352 DLGSUP INFO GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151) MTC@a6473498aab6: External command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh> SGSN_Tests.TC_hlr_location_cancel_request_withdraw pass' was executed successfully (exit status: 0). MTC@a6473498aab6: Starting external command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh> SGSN_Tests.TC_hlr_location_cancel_request_unknown_subscriber_withdraw'. ------ SGSN_Tests.TC_hlr_location_cancel_request_unknown_subscriber_withdraw ------ Fri Aug 16 12:03:21 UTC 2024 /usr/bin/dumpcap -q -s 1520 -n -i any -w "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/165/artifact/logs/testsuite/SGSN_Tests.TC_hlr_location_cancel_request_unknown_subscriber_withdraw.pcap"> ><https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/165/artifact/logs/testsuite/SGSN_Tests.TC_hlr_location_cancel_request_unknown_subscriber_withdraw.pcap.stdout> 2>/tmp/cmderr & Waiting for packet dumper to start... 0 20240816120322353 DLGSUP NOTICE GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74) 20240816120322353 DLGSUP INFO GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151) MTC@a6473498aab6: External command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh> SGSN_Tests.TC_hlr_location_cancel_request_unknown_subscriber_withdraw' was executed successfully (exit status: 0). MTC@a6473498aab6: Test case TC_hlr_location_cancel_request_unknown_subscriber_withdraw started. 20240816120322474 DLGLOBAL INFO Accept()ed new telnet connection r=127.0.0.1:58490<->l=127.0.0.10:4245 (telnet_interface.c:192) 20240816120322476 DLGTP INFO Clearing req & resp retransmit queues (gsn.c:365) SGSN_Test-Gb0-NS0(403)@a6473498aab6: Creating NSIP provider for "127.0.0.103":21010 SGSN_Test-Gb0-BSSGP0(404)@a6473498aab6: BVCI(0) State Transition: BVC_S_WAIT_RESET (0) -> BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) SGSN_Test-Gb0-NS0(403)@a6473498aab6: Starting NSVC component for { provider := { ip := { address_family := AF_INET (2), local_udp_port := 21010, local_ip := "127.0.0.103", remote_udp_port := 23000, remote_ip := "127.0.0.10", data_weight := 1, signalling_weight := 1 } }, nsvci := 97 } -NSVCI97(407)@a6473498aab6: NSVC 97 State Transition: NSVC_S_DEAD_BLOCKED (1) -> NSVC_S_DEAD_BLOCKED (1) -NSVCI97(407)@a6473498aab6: Provider Link came up: sending NS-RESET 20240816120322515 DLNSSIGNAL INFO NSE(00096)-NSVC(00097) Rx NS-RESET (gprs_ns2.c:1309) 20240816120322515 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x555bfb2dbe10]{UNBLOCKED}: Received Event RX-RESET (gprs_ns2_vc_fsm.c:934) 20240816120322515 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x555bfb2dbe10]{UNBLOCKED}: state_chg to RESET (gprs_ns2_vc_fsm.c:657) 20240816120322515 DLNS NOTICE NSE(00096) NS-STATUS.ind(bvci=00000): cause=NSE failure, transfer=0, first=0, mtu=65523 (gprs_ns2.c:575) 20240816120322515 DGPRS NOTICE NS-E 96 became unavailable (gprs_ns.c:54) 20240816120322515 DLNSSIGNAL INFO NSE(00096)-NSVC(00097) Tx NS-RESET-ACK (gprs_ns2_message.c:331) 20240816120322515 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x555bfb2dbe10]{RESET}: state_chg to BLOCKED (gprs_ns2_vc_fsm.c:329) 20240816120322515 DLNSSIGNAL INFO NSE(00096)-NSVC(00097) Tx NS-ALIVE (gprs_ns2_message.c:193) 20240816120322515 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x555bfb2dbe10]{BLOCKED}: Starting Tns-alive of 3 seconds (gprs_ns2_vc_fsm.c:177) -NSVCI97(407)@a6473498aab6: NSVC 97 State Transition: NSVC_S_WAIT_RESET (2) -> NSVC_S_ALIVE_BLOCKED (3) 20240816120322516 DLNSSIGNAL INFO NSE(00096)-NSVC(00097) Rx NS-ALIVE (gprs_ns2.c:1309) 20240816120322516 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x555bfb2dbe10]{BLOCKED}: Received Event RX-ALIVE (gprs_ns2_vc_fsm.c:957) 20240816120322516 DLNSSIGNAL INFO NSE(00096)-NSVC(00097) Tx NS-ALIVE-ACK (gprs_ns2_message.c:193) 20240816120322516 DLNSSIGNAL INFO NSE(00096)-NSVC(00097) Rx NS-UNBLOCK (gprs_ns2.c:1309) 20240816120322516 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x555bfb2dbe10]{BLOCKED}: Received Event RX-UNBLOCK (gprs_ns2_vc_fsm.c:951) 20240816120322516 DLNSSIGNAL INFO NSE(00096)-NSVC(00097) Tx NS-UNBLOCK-ACK (gprs_ns2_message.c:193) 20240816120322516 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x555bfb2dbe10]{BLOCKED}: state_chg to UNBLOCKED (gprs_ns2_vc_fsm.c:414) 20240816120322516 DLNS NOTICE NSE(00096) NS-STATUS.ind(bvci=00000): cause=NSE recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:575) 20240816120322516 DGPRS NOTICE NS-E 96 became available (gprs_ns.c:43) 20240816120322516 DLNS NOTICE NSE(00096)-NSVC(00097) NS-STATUS.ind(bvci=00000): cause=NSVC recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:571) 20240816120322516 DGPRS NOTICE NS: indication Unknown prim 2 from NS (gprs_ns.c:57) 20240816120322516 DLNSSIGNAL INFO NSE(00096)-NSVC(00097) Rx NS-ALIVE-ACK (gprs_ns2.c:1309) 20240816120322516 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x555bfb2dbe10]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960) -NSVCI97(407)@a6473498aab6: Rx NS-ALIVE-ACK: stopping Tns-alive; starting Tns-test -NSVCI97(407)@a6473498aab6: NSVC 97 State Transition: NSVC_S_ALIVE_BLOCKED (3) -> NSVC_S_ALIVE_UNBLOCKED (4) 20240816120322517 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x555bfb2dbe10]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964) SGSN_Test-Gb1-NS1(408)@a6473498aab6: Creating NSIP provider for "127.0.0.103":21011 SGSN_Test-Gb0-BSSGP0(404)@a6473498aab6: BVCI(0) Rx BVC-RESET-ACK SGSN_Test-Gb0-BSSGP0(404)@a6473498aab6: BVCI(0) State Transition: BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) -> BVC_S_UNBLOCKED (3) 20240816120322521 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x555bfb2dbe10]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964) 20240816120322521 DLBSSGP NOTICE Cell 262-42-13135-0 CI 20960 on BVCI 196 (gprs_bssgp.c:400) TC_hlr_location_cancel_request_unknown_subscriber_withdraw-BVCI196(406)@a6473498aab6: BVCI(196) State Transition: BVC_S_BLOCKED (2) -> BVC_S_UNBLOCKED (3) SGSN_Test-Gb1-BSSGP1(409)@a6473498aab6: BVCI(0) State Transition: BVC_S_WAIT_RESET (0) -> BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) SGSN_Test-Gb1-NS1(408)@a6473498aab6: Starting NSVC component for { provider := { ip := { address_family := AF_INET (2), local_udp_port := 21011, local_ip := "127.0.0.103", remote_udp_port := 23000, remote_ip := "127.0.0.10", data_weight := 1, signalling_weight := 1 } }, nsvci := 98 } -NSVCI98(412)@a6473498aab6: NSVC 98 State Transition: NSVC_S_DEAD_BLOCKED (1) -> NSVC_S_DEAD_BLOCKED (1) -NSVCI98(412)@a6473498aab6: Provider Link came up: sending NS-RESET 20240816120322529 DLNSSIGNAL INFO NSE(00097)-NSVC(00098) Rx NS-RESET (gprs_ns2.c:1309) 20240816120322529 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x555bfb2de2a0]{UNBLOCKED}: Received Event RX-RESET (gprs_ns2_vc_fsm.c:934) 20240816120322529 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x555bfb2de2a0]{UNBLOCKED}: state_chg to RESET (gprs_ns2_vc_fsm.c:657) 20240816120322529 DLNS NOTICE NSE(00097) NS-STATUS.ind(bvci=00000): cause=NSE failure, transfer=0, first=0, mtu=65523 (gprs_ns2.c:575) 20240816120322529 DGPRS NOTICE NS-E 97 became unavailable (gprs_ns.c:54) 20240816120322529 DLNSSIGNAL INFO NSE(00097)-NSVC(00098) Tx NS-RESET-ACK (gprs_ns2_message.c:331) 20240816120322529 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x555bfb2de2a0]{RESET}: state_chg to BLOCKED (gprs_ns2_vc_fsm.c:329) 20240816120322529 DLNSSIGNAL INFO NSE(00097)-NSVC(00098) Tx NS-ALIVE (gprs_ns2_message.c:193) 20240816120322529 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x555bfb2de2a0]{BLOCKED}: Starting Tns-alive of 3 seconds (gprs_ns2_vc_fsm.c:177) 20240816120322530 DLNSSIGNAL INFO NSE(00097)-NSVC(00098) Rx NS-ALIVE (gprs_ns2.c:1309) 20240816120322530 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x555bfb2de2a0]{BLOCKED}: Received Event RX-ALIVE (gprs_ns2_vc_fsm.c:957) -NSVCI98(412)@a6473498aab6: NSVC 98 State Transition: NSVC_S_WAIT_RESET (2) -> NSVC_S_ALIVE_BLOCKED (3) 20240816120322530 DLNSSIGNAL INFO NSE(00097)-NSVC(00098) Tx NS-ALIVE-ACK (gprs_ns2_message.c:193) 20240816120322530 DLNSSIGNAL INFO NSE(00097)-NSVC(00098) Rx NS-UNBLOCK (gprs_ns2.c:1309) 20240816120322530 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x555bfb2de2a0]{BLOCKED}: Received Event RX-UNBLOCK (gprs_ns2_vc_fsm.c:951) 20240816120322530 DLNSSIGNAL INFO NSE(00097)-NSVC(00098) Tx NS-UNBLOCK-ACK (gprs_ns2_message.c:193) 20240816120322530 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x555bfb2de2a0]{BLOCKED}: state_chg to UNBLOCKED (gprs_ns2_vc_fsm.c:414) 20240816120322530 DLNS NOTICE NSE(00097) NS-STATUS.ind(bvci=00000): cause=NSE recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:575) 20240816120322530 DGPRS NOTICE NS-E 97 became available (gprs_ns.c:43) 20240816120322530 DLNS NOTICE NSE(00097)-NSVC(00098) NS-STATUS.ind(bvci=00000): cause=NSVC recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:571) 20240816120322530 DGPRS NOTICE NS: indication Unknown prim 2 from NS (gprs_ns.c:57) 20240816120322530 DLNSSIGNAL INFO NSE(00097)-NSVC(00098) Rx NS-ALIVE-ACK (gprs_ns2.c:1309) 20240816120322530 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x555bfb2de2a0]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960) -NSVCI98(412)@a6473498aab6: Rx NS-ALIVE-ACK: stopping Tns-alive; starting Tns-test -NSVCI98(412)@a6473498aab6: NSVC 98 State Transition: NSVC_S_ALIVE_BLOCKED (3) -> NSVC_S_ALIVE_UNBLOCKED (4) 20240816120322532 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x555bfb2de2a0]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964) SGSN_Test-Gb2-NS2(413)@a6473498aab6: Creating NSIP provider for "127.0.0.103":21012 SGSN_Test-Gb1-BSSGP1(409)@a6473498aab6: BVCI(0) Rx BVC-RESET-ACK SGSN_Test-Gb1-BSSGP1(409)@a6473498aab6: BVCI(0) State Transition: BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) -> BVC_S_UNBLOCKED (3) 20240816120322535 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x555bfb2de2a0]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964) 20240816120322536 DLBSSGP NOTICE Cell 262-42-13200-0 CI 20961 on BVCI 210 (gprs_bssgp.c:400) TC_hlr_location_cancel_request_unknown_subscriber_withdraw-BVCI210(411)@a6473498aab6: BVCI(210) State Transition: BVC_S_BLOCKED (2) -> BVC_S_UNBLOCKED (3) SGSN_Test-Gb2-BSSGP2(414)@a6473498aab6: BVCI(0) State Transition: BVC_S_WAIT_RESET (0) -> BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) SGSN_Test-Gb2-NS2(413)@a6473498aab6: Starting NSVC component for { provider := { ip := { address_family := AF_INET (2), local_udp_port := 21012, local_ip := "127.0.0.103", remote_udp_port := 23000, remote_ip := "127.0.0.10", data_weight := 1, signalling_weight := 1 } }, nsvci := 99 } -NSVCI99(417)@a6473498aab6: NSVC 99 State Transition: NSVC_S_DEAD_BLOCKED (1) -> NSVC_S_DEAD_BLOCKED (1) -NSVCI99(417)@a6473498aab6: Provider Link came up: sending NS-RESET 20240816120322543 DLNSSIGNAL INFO NSE(00098)-NSVC(00099) Rx NS-RESET (gprs_ns2.c:1309) 20240816120322543 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x555bfb2dfd00]{UNBLOCKED}: Received Event RX-RESET (gprs_ns2_vc_fsm.c:934) 20240816120322543 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x555bfb2dfd00]{UNBLOCKED}: state_chg to RESET (gprs_ns2_vc_fsm.c:657) 20240816120322544 DLNS NOTICE NSE(00098) NS-STATUS.ind(bvci=00000): cause=NSE failure, transfer=0, first=0, mtu=65523 (gprs_ns2.c:575) 20240816120322544 DGPRS NOTICE NS-E 98 became unavailable (gprs_ns.c:54) 20240816120322544 DLNSSIGNAL INFO NSE(00098)-NSVC(00099) Tx NS-RESET-ACK (gprs_ns2_message.c:331) 20240816120322544 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x555bfb2dfd00]{RESET}: state_chg to BLOCKED (gprs_ns2_vc_fsm.c:329) 20240816120322544 DLNSSIGNAL INFO NSE(00098)-NSVC(00099) Tx NS-ALIVE (gprs_ns2_message.c:193) 20240816120322544 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x555bfb2dfd00]{BLOCKED}: Starting Tns-alive of 3 seconds (gprs_ns2_vc_fsm.c:177) -NSVCI99(417)@a6473498aab6: NSVC 99 State Transition: NSVC_S_WAIT_RESET (2) -> NSVC_S_ALIVE_BLOCKED (3) 20240816120322544 DLNSSIGNAL INFO NSE(00098)-NSVC(00099) Rx NS-ALIVE (gprs_ns2.c:1309) 20240816120322544 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x555bfb2dfd00]{BLOCKED}: Received Event RX-ALIVE (gprs_ns2_vc_fsm.c:957) 20240816120322544 DLNSSIGNAL INFO NSE(00098)-NSVC(00099) Tx NS-ALIVE-ACK (gprs_ns2_message.c:193) 20240816120322544 DLNSSIGNAL INFO NSE(00098)-NSVC(00099) Rx NS-UNBLOCK (gprs_ns2.c:1309) 20240816120322544 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x555bfb2dfd00]{BLOCKED}: Received Event RX-UNBLOCK (gprs_ns2_vc_fsm.c:951) 20240816120322544 DLNSSIGNAL INFO NSE(00098)-NSVC(00099) Tx NS-UNBLOCK-ACK (gprs_ns2_message.c:193) 20240816120322544 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x555bfb2dfd00]{BLOCKED}: state_chg to UNBLOCKED (gprs_ns2_vc_fsm.c:414) 20240816120322544 DLNS NOTICE NSE(00098) NS-STATUS.ind(bvci=00000): cause=NSE recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:575) 20240816120322544 DGPRS NOTICE NS-E 98 became available (gprs_ns.c:43) 20240816120322544 DLNS NOTICE NSE(00098)-NSVC(00099) NS-STATUS.ind(bvci=00000): cause=NSVC recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:571) 20240816120322544 DGPRS NOTICE NS: indication Unknown prim 2 from NS (gprs_ns.c:57) 20240816120322544 DLNSSIGNAL INFO NSE(00098)-NSVC(00099) Rx NS-ALIVE-ACK (gprs_ns2.c:1309) 20240816120322544 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x555bfb2dfd00]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960) -NSVCI99(417)@a6473498aab6: Rx NS-ALIVE-ACK: stopping Tns-alive; starting Tns-test -NSVCI99(417)@a6473498aab6: NSVC 99 State Transition: NSVC_S_ALIVE_BLOCKED (3) -> NSVC_S_ALIVE_UNBLOCKED (4) 20240816120322546 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x555bfb2dfd00]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964) SGSN_Test-Gb2-BSSGP2(414)@a6473498aab6: BVCI(0) Rx BVC-RESET-ACK SGSN_Test-Gb2-BSSGP2(414)@a6473498aab6: BVCI(0) State Transition: BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) -> BVC_S_UNBLOCKED (3) 20240816120322549 DLNS DEBUG GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x555bfb2dfd00]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964) 20240816120322549 DLBSSGP NOTICE Cell 262-42-13200-0 CI 20962 on BVCI 220 (gprs_bssgp.c:400) TC_hlr_location_cancel_request_unknown_subscriber_withdraw-BVCI220(416)@a6473498aab6: BVCI(220) State Transition: BVC_S_BLOCKED (2) -> BVC_S_UNBLOCKED (3) 20240816120323354 DLGSUP NOTICE GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74) 20240816120323354 DLINP NOTICE 127.0.0.103:4222 connection done (ipa.c:143) 20240816120323354 DLGSUP INFO GSUP link to 127.0.0.103:4222 UP (gsup_client.c:151) 20240816120323354 DLGSUP DEBUG GSUP sending PING (gsup_client.c:288) SGSN_Test-GSUP-IPA(418)@a6473498aab6: Established a new IPA connection (conn_id=2) SGSN_Test-GSUP-IPA(418)@a6473498aab6: CCM Tx:{ msg_type := IPAC_MSGT_ID_GET (4), u := { get := { { len := 1, tag := IPAC_IDTAG_UNITNAME (1) }, { len := 1, tag := IPAC_IDTAG_UNITID (8) } } } } 20240816120323358 DLINP NOTICE received ID_GET for unit ID 0/0/0 (ipaccess.c:897) SGSN_Test-GSUP-IPA(418)@a6473498aab6: CCM Rx:{ msg_type := IPAC_MSGT_PING (0), u := omit } SGSN_Test-GSUP-IPA(418)@a6473498aab6: CCM Tx:{ msg_type := IPAC_MSGT_PONG (1), u := omit } SGSN_Test-GSUP-IPA(418)@a6473498aab6: CCM Rx:{ msg_type := IPAC_MSGT_ID_RESP (5), u := { resp := { { len := 24, tag := IPAC_IDTAG_UNITNAME (1), data := '5347534E2D30302D30302D30302D30302D30302D303000'O }, { len := 7, tag := IPAC_IDTAG_UNITID (8), data := '302F302F3000'O } } } } SGSN_Test-GSUP-IPA(418)@a6473498aab6: IPA ID RESP: { { len := 24, tag := IPAC_IDTAG_UNITNAME (1), data := '5347534E2D30302D30302D30302D30302D30302D303000'O }, { len := 7, tag := IPAC_IDTAG_UNITID (8), data := '302F302F3000'O } } 20240816120323359 DLGSUP DEBUG GSUP receiving PONG (gsup_client.c:225) SGSN_Test-GSUP-IPA(418)@a6473498aab6: CCM Tx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } SGSN_Test-GSUP-IPA(418)@a6473498aab6: CCM Rx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_hlr_location_cancel_request_unknown_subscriber_withdraw-BVCI196(406)@a6473498aab6: Adding Client=TC_hlr_location_cancel_request_unknown_subscriber_withdraw(421), IMSI='262420000000030'H, TLLI='F55B3882'O, index=0 SGSN_Test-GSUP(419)@a6473498aab6: Created GsupExpect[0] for "262420000000030" to be handled at TC_hlr_location_cancel_request_unknown_subscriber_withdraw(421) 20240816120324393 DGPRS INFO SUBSCR(---) Sending GSUP, will send: 1d 01 08 62 42 02 00 00 00 30 f0 02 01 02 28 01 01 (gprs_subscriber.c:210) 20240816120324393 DGPRS NOTICE Unknown IMSI 262420000000030, discarding GSUP request of type 0x1c (gprs_subscriber.c:661) SGSN_Test-GSUP(419)@a6473498aab6: Found GsupExpect[0] for "262420000000030" handled at TC_hlr_location_cancel_request_unknown_subscriber_withdraw(421) SGSN_Test-GSUP(419)@a6473498aab6: Added IMSI table entry 0TC_hlr_location_cancel_request_unknown_subscriber_withdraw(421)"262420000000030" TC_hlr_location_cancel_request_unknown_subscriber_withdraw(421)@a6473498aab6: setverdict(pass): none -> pass TC_hlr_location_cancel_request_unknown_subscriber_withdraw-BVCI196(406)@a6473498aab6: Removing Client IMSI='262420000000030'H, index=0 TC_hlr_location_cancel_request_unknown_subscriber_withdraw(421)@a6473498aab6: Final verdict of PTC: pass 20240816120324396 DLGLOBAL INFO Closing telnet connection r=127.0.0.1:58490<->l=127.0.0.10:4245 (telnet_interface.c:138) SGSN_Test-Gb1-BSSGP1(409)@a6473498aab6: Final verdict of PTC: none TC_hlr_location_cancel_request_unknown_subscriber_withdraw-BVCI210(411)@a6473498aab6: Final verdict of PTC: none TC_hlr_location_cancel_request_unknown_subscriber_withdraw-BVCI196(406)@a6473498aab6: Final verdict of PTC: none SGSN_Test-GSUP-IPA(418)@a6473498aab6: Final verdict of PTC: none 20240816120324398 DLINP ERROR 127.0.0.103:4222 connection closed with server (ipa.c:68) 20240816120324398 DLGSUP INFO GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151) SGSN_Test-Gb1-NS1(408)@a6473498aab6: Final verdict of PTC: none -NSVCI97-provIP(405)@a6473498aab6: Final verdict of PTC: none SGSN_Test-Gb2-BSSGP2(414)@a6473498aab6: Final verdict of PTC: none -NSVCI98(412)@a6473498aab6: Final verdict of PTC: none -NSVCI99(417)@a6473498aab6: Final verdict of PTC: none TC_hlr_location_cancel_request_unknown_subscriber_withdraw-BVCI220(416)@a6473498aab6: Final verdict of PTC: none -NSVCI98-provIP(410)@a6473498aab6: Final verdict of PTC: none -NSVCI97(407)@a6473498aab6: Final verdict of PTC: none SGSN_Test-Gb0-NS0(403)@a6473498aab6: Final verdict of PTC: none -NSVCI99-provIP(415)@a6473498aab6: Final verdict of PTC: none SGSN_Test-Gb2-NS2(413)@a6473498aab6: Final verdict of PTC: none SGSN_Test-GSUP(419)@a6473498aab6: Final verdict of PTC: none SGSN_Test-GGSN_GTP(420)@a6473498aab6: Final verdict of PTC: none SGSN_Test-Gb0-BSSGP0(404)@a6473498aab6: Final verdict of PTC: none MTC@a6473498aab6: Setting final verdict of the test case. MTC@a6473498aab6: Local verdict of MTC: none MTC@a6473498aab6: Local verdict of PTC SGSN_Test-Gb0-NS0(403): none (none -> none) MTC@a6473498aab6: Local verdict of PTC SGSN_Test-Gb0-BSSGP0(404): none (none -> none) MTC@a6473498aab6: Local verdict of PTC -NSVCI97-provIP(405): none (none -> none) MTC@a6473498aab6: Local verdict of PTC TC_hlr_location_cancel_request_unknown_subscriber_withdraw-BVCI196(406): none (none -> none) MTC@a6473498aab6: Local verdict of PTC -NSVCI97(407): none (none -> none) MTC@a6473498aab6: Local verdict of PTC SGSN_Test-Gb1-NS1(408): none (none -> none) MTC@a6473498aab6: Local verdict of PTC SGSN_Test-Gb1-BSSGP1(409): none (none -> none) MTC@a6473498aab6: Local verdict of PTC -NSVCI98-provIP(410): none (none -> none) MTC@a6473498aab6: Local verdict of PTC TC_hlr_location_cancel_request_unknown_subscriber_withdraw-BVCI210(411): none (none -> none) MTC@a6473498aab6: Local verdict of PTC -NSVCI98(412): none (none -> none) MTC@a6473498aab6: Local verdict of PTC SGSN_Test-Gb2-NS2(413): none (none -> none) MTC@a6473498aab6: Local verdict of PTC SGSN_Test-Gb2-BSSGP2(414): none (none -> none) MTC@a6473498aab6: Local verdict of PTC -NSVCI99-provIP(415): none (none -> none) MTC@a6473498aab6: Local verdict of PTC TC_hlr_location_cancel_request_unknown_subscriber_withdraw-BVCI220(416): none (none -> none) MTC@a6473498aab6: Local verdict of PTC -NSVCI99(417): none (none -> none) MTC@a6473498aab6: Local verdict of PTC SGSN_Test-GSUP-IPA(418): none (none -> none) MTC@a6473498aab6: Local verdict of PTC SGSN_Test-GSUP(419): none (none -> none) MTC@a6473498aab6: Local verdict of PTC SGSN_Test-GGSN_GTP(420): none (none -> none) MTC@a6473498aab6: Local verdict of PTC TC_hlr_location_cancel_request_unknown_subscriber_withdraw(421): pass (none -> pass) MTC@a6473498aab6: Test case TC_hlr_location_cancel_request_unknown_subscriber_withdraw finished. Verdict: pass MTC@a6473498aab6: Starting external command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh> SGSN_Tests.TC_hlr_location_cancel_request_unknown_subscriber_withdraw pass'. Fri Aug 16 12:03:24 UTC 2024 ====== SGSN_Tests.TC_hlr_location_cancel_request_unknown_subscriber_withdraw pass ====== Waiting for packet dumper to finish... 0 (prev_count=-1, count=44516) Error: OCI runtime error: crun: the container `a6473498aab6080cd310c2e7facb778be7ff0a6ff937d362d2a2b2e7e29100c7` is not running [testenv] podman container crashed! [testenv][generic] Testsuite is done [testenv][generic] Stopping testsuite (2699682) [testenv][generic] Merging log files [testenv][generic] + ['podman', 'exec', '-e', 'CCACHE_DIR=/home/osmocom-build/ccache/testenv', '-e', 'TESTENV_CACHE_DIR=<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache',> '-e', 'TESTENV_SRC_DIR=/home/osmocom-build/jenkins/workspace', '-e', 'TERM=dumb', '-e', 'TESTENV_GIT_DIR=<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/git',> '-e', 'PATH=<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_testenv/data/scripts>:<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/podman/osmo-ttcn3-hacks/sgsn>:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin', '-e', 'HOME=/home/osmocom-build', '-t', '-w', '<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/165/artifact/logs/testsuite',> 'testenv-sgsn-generic-osmocom-nightly-20240816-1158-a86509fe', 'sh', '-c', '<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/podman/osmo-ttcn3-hacks/log_merge.sh> SGSN_Tests --rm >/dev/null'] Error: no container with name or ID "testenv-sgsn-generic-osmocom-nightly-20240816-1158-a86509fe" found: no such container [testenv][generic] Command failed unexpectedly [testenv][generic] Command: ['podman', 'exec', '-e', 'CCACHE_DIR=/home/osmocom-build/ccache/testenv', '-e', 'TESTENV_CACHE_DIR=<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache',> '-e', 'TESTENV_SRC_DIR=/home/osmocom-build/jenkins/workspace', '-e', 'TERM=dumb', '-e', 'TESTENV_GIT_DIR=<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/git',> '-e', 'PATH=<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_testenv/data/scripts>:<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/podman/osmo-ttcn3-hacks/sgsn>:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin', '-e', 'HOME=/home/osmocom-build', '-t', '-w', '<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/165/artifact/logs/testsuite',> 'testenv-sgsn-generic-osmocom-nightly-20240816-1158-a86509fe', 'sh', '-c', '<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/podman/osmo-ttcn3-hacks/log_merge.sh> SGSN_Tests --rm >/dev/null'] [testenv][generic] Returncode: 125 Traceback (most recent call last): File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/./testenv.py",> line 115, in <module> main() File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/./testenv.py",> line 104, in main run() File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/./testenv.py",> line 63, in run testenv.testsuite.run(cfg) File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_testenv/testenv/testsuite.py",> line 199, in run merge_log_files(cfg) File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_testenv/testenv/testsuite.py",> line 131, in merge_log_files testenv.cmd.run(cmd, cwd=cwd) File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_testenv/testenv/cmd.py",> line 86, in run return testenv.podman.exec_cmd(cmd, check=check, env=env, *args, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_testenv/testenv/podman.py",> line 133, in exec_cmd testenv.cmd.run( File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_testenv/testenv/cmd.py",> line 103, in run exit_error_cmd(p, "Command failed unexpectedly") File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_testenv/testenv/cmd.py",> line 59, in exit_error_cmd raise RuntimeError("shell command related error, find details right above this python trace") RuntimeError: shell command related error, find details right above this python trace [testenv][generic] Logs saved to: https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/165/artifa…  Build step 'Execute shell' marked build as failure Recording test results [Checks API] No suitable checks publisher found.