- jenkins-notifications - lists.osmocom.org

Build failed in Jenkins: ttcn3-sgsn-test-io_uring #169
by jenkins＠lists.osmocom.org 20 Aug '24

20 Aug '24

See <https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/169/displa…> Changes: [Pau Espin Pedrol] ggsn: Split test and relax expectations testing gtpu access over ipv6 [Pau Espin Pedrol] sgsn: Fix running with testenv.py podman setup [Pau Espin Pedrol] sgsn: Introduce test TC_attach_rau_a_b_wrong_old_ra ------------------------------------------ [...truncated 985.96 KB...] [1;33m20240820120147445 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x558fdf4b4580]{CheckIdentity}: Timeout of T3370 (fsm.c:317)[0;m [1;33m20240820120147445 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000032/f6935c18) <- GMM IDENTITY REQUEST: mi_type=IMEI (gprs_gmm.c:431)[0;m [38;5;63m20240820120151520 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;63m20240820120151521 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20240820120151521 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x558fdf4aee10]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960)[0;m [38;5;63m20240820120151538 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;63m20240820120151539 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20240820120151539 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x558fdf4b12a0]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960)[0;m [38;5;63m20240820120151554 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;63m20240820120151556 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20240820120151556 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x558fdf4b2d00]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960)[0;m [1;33m20240820120153446 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x558fdf4b4580]{CheckIdentity}: Timeout of T3370 (fsm.c:317)[0;m [1;33m20240820120153446 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x558fdf4b4580]{CheckIdentity}: Received Event E_REJECT (gprs_gmm_attach.c:422)[0;m [1;33m20240820120153446 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x558fdf4b4580]{CheckIdentity}: state_chg to Reject (gprs_gmm_attach.c:397)[0;m [1;33m20240820120153446 [1;33mDMM[0;m[1;33m [1;33mNOTICE[0;m[1;33m MM(262420000000032/f6935c18) <- GMM ATTACH REJECT: MS identity cannot be derived by the network (gprs_gmm.c:364)[0;m [1;33m20240820120153446 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x558fdf4b4580]{Reject}: Deallocated (fsm.c:568)[0;m [1;33m20240820120153446 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Gb(0)[0x558fdf4b46b0]{Idle}: Deallocated (fsm.c:568)[0;m [1;33m20240820120153446 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Iu[0x558fdf4b47e0]{Detached}: Deallocated (fsm.c:568)[0;m [1;33m20240820120153446 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM(gmm_fsm)[0x558fdf4b4450]{CommonProcedureInitiated}: Deallocated (fsm.c:568)[0;m 20240820120153446 [1;33mDLLC[0;m [1;33mNOTICE[0;m LLME(f5445ec1/f6935c18){ASSIGNED} LLGM Assign pre (f6935c18 => ffffffff) (gprs_llc.c:1079) 20240820120153446 [1;33mDLLC[0;m [1;33mNOTICE[0;m LLME(00000000/00000000){UNASSIGNED} LLGM Assign post (f6935c18 => ffffffff) (gprs_llc.c:1125) TC_attach_no_imei_response(269)@1c739be12bc2: setverdict(pass): none -> pass TC_attach_no_imei_response-BVCI196(254)@1c739be12bc2: Removing Client IMSI='262420000000032'H, index=0 TC_attach_no_imei_response(269)@1c739be12bc2: Final verdict of PTC: pass 20240820120153453 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m Closing telnet connection r=127.0.0.1:59770<->l=127.0.0.10:4245 (telnet_interface.c:138) SGSN_Test-Gb2-NS2(261)@1c739be12bc2: Final verdict of PTC: none SGSN_Test-Gb0-NS0(251)@1c739be12bc2: Final verdict of PTC: none TC_attach_no_imei_response-BVCI220(264)@1c739be12bc2: Final verdict of PTC: none -NSVCI98(260)@1c739be12bc2: Final verdict of PTC: none SGSN_Test-Gb1-BSSGP1(257)@1c739be12bc2: Final verdict of PTC: none SGSN_Test-Gb0-BSSGP0(252)@1c739be12bc2: Final verdict of PTC: none -NSVCI99(265)@1c739be12bc2: Final verdict of PTC: none SGSN_Test-GSUP(267)@1c739be12bc2: Final verdict of PTC: none [38;5;23m20240820120153456 [1;31mDLINP[0;m[38;5;23m [1;31mERROR[0;m[38;5;23m 127.0.0.103:4222 connection closed with server (ipa.c:68)[0;m [38;5;39m20240820120153456 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151)[0;m SGSN_Test-Gb1-NS1(256)@1c739be12bc2: Final verdict of PTC: none -NSVCI98-provIP(258)@1c739be12bc2: Final verdict of PTC: none -NSVCI97-provIP(253)@1c739be12bc2: Final verdict of PTC: none TC_attach_no_imei_response-BVCI210(259)@1c739be12bc2: Final verdict of PTC: none TC_attach_no_imei_response-BVCI196(254)@1c739be12bc2: Final verdict of PTC: none -NSVCI99-provIP(263)@1c739be12bc2: Final verdict of PTC: none -NSVCI97(255)@1c739be12bc2: Final verdict of PTC: none SGSN_Test-GGSN_GTP(268)@1c739be12bc2: Final verdict of PTC: none SGSN_Test-GSUP-IPA(266)@1c739be12bc2: Final verdict of PTC: none SGSN_Test-Gb2-BSSGP2(262)@1c739be12bc2: Final verdict of PTC: none MTC@1c739be12bc2: Setting final verdict of the test case. MTC@1c739be12bc2: Local verdict of MTC: none MTC@1c739be12bc2: Local verdict of PTC SGSN_Test-Gb0-NS0(251): none (none -> none) MTC@1c739be12bc2: Local verdict of PTC SGSN_Test-Gb0-BSSGP0(252): none (none -> none) MTC@1c739be12bc2: Local verdict of PTC -NSVCI97-provIP(253): none (none -> none) MTC@1c739be12bc2: Local verdict of PTC TC_attach_no_imei_response-BVCI196(254): none (none -> none) MTC@1c739be12bc2: Local verdict of PTC -NSVCI97(255): none (none -> none) MTC@1c739be12bc2: Local verdict of PTC SGSN_Test-Gb1-NS1(256): none (none -> none) MTC@1c739be12bc2: Local verdict of PTC SGSN_Test-Gb1-BSSGP1(257): none (none -> none) MTC@1c739be12bc2: Local verdict of PTC -NSVCI98-provIP(258): none (none -> none) MTC@1c739be12bc2: Local verdict of PTC TC_attach_no_imei_response-BVCI210(259): none (none -> none) MTC@1c739be12bc2: Local verdict of PTC -NSVCI98(260): none (none -> none) MTC@1c739be12bc2: Local verdict of PTC SGSN_Test-Gb2-NS2(261): none (none -> none) MTC@1c739be12bc2: Local verdict of PTC SGSN_Test-Gb2-BSSGP2(262): none (none -> none) MTC@1c739be12bc2: Local verdict of PTC -NSVCI99-provIP(263): none (none -> none) MTC@1c739be12bc2: Local verdict of PTC TC_attach_no_imei_response-BVCI220(264): none (none -> none) MTC@1c739be12bc2: Local verdict of PTC -NSVCI99(265): none (none -> none) MTC@1c739be12bc2: Local verdict of PTC SGSN_Test-GSUP-IPA(266): none (none -> none) MTC@1c739be12bc2: Local verdict of PTC SGSN_Test-GSUP(267): none (none -> none) MTC@1c739be12bc2: Local verdict of PTC SGSN_Test-GGSN_GTP(268): none (none -> none) MTC@1c739be12bc2: Local verdict of PTC TC_attach_no_imei_response(269): pass (none -> pass) MTC@1c739be12bc2: Test case TC_attach_no_imei_response finished. Verdict: pass MTC@1c739be12bc2: Starting external command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/…> SGSN_Tests.TC_attach_no_imei_response pass'. Tue Aug 20 12:01:53 UTC 2024 [1;32m====== SGSN_Tests.TC_attach_no_imei_response pass ======[0m Waiting for packet dumper to finish... 0 (prev_count=-1, count=62632) [38;5;39m20240820120154457 [1;33mDLGSUP[0;m[38;5;39m [1;33mNOTICE[0;m[38;5;39m GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74)[0;m [38;5;39m20240820120154457 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151)[0;m Waiting for packet dumper to finish... 1 (prev_count=62632, count=67152) [38;5;39m20240820120155458 [1;33mDLGSUP[0;m[38;5;39m [1;33mNOTICE[0;m[38;5;39m GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74)[0;m [38;5;39m20240820120155458 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151)[0;m MTC@1c739be12bc2: External command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/…> SGSN_Tests.TC_attach_no_imei_response pass' was executed successfully (exit status: 0). MTC@1c739be12bc2: Starting external command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/…> SGSN_Tests.TC_attach_no_imsi_response'. ------ SGSN_Tests.TC_attach_no_imsi_response ------ Tue Aug 20 12:01:55 UTC 2024 /usr/bin/dumpcap -q -s 1520 -n -i any -w "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/169/artifa…"> ><https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/169/artifa…> 2>/tmp/cmderr & Waiting for packet dumper to start... 0 [38;5;39m20240820120156459 [1;33mDLGSUP[0;m[38;5;39m [1;33mNOTICE[0;m[38;5;39m GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74)[0;m [38;5;39m20240820120156459 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151)[0;m MTC@1c739be12bc2: External command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/…> SGSN_Tests.TC_attach_no_imsi_response' was executed successfully (exit status: 0). MTC@1c739be12bc2: Test case TC_attach_no_imsi_response started. 20240820120156667 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m Accept()ed new telnet connection r=127.0.0.1:49296<->l=127.0.0.10:4245 (telnet_interface.c:192) [38;5;35m20240820120156668 [1;32mDLGTP[0;m[38;5;35m [1;32mINFO[0;m[38;5;35m Clearing req & resp retransmit queues (gsn.c:365)[0;m SGSN_Test-Gb0-NS0(270)@1c739be12bc2: Creating NSIP provider for "127.0.0.103":21010 SGSN_Test-Gb0-BSSGP0(271)@1c739be12bc2: BVCI(0) State Transition: BVC_S_WAIT_RESET (0) -> BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) SGSN_Test-Gb0-NS0(270)@1c739be12bc2: 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(275)@1c739be12bc2: NSVC 97 State Transition: NSVC_S_DEAD_BLOCKED (1) -> NSVC_S_DEAD_BLOCKED (1) -NSVCI97(275)@1c739be12bc2: Provider Link came up: sending NS-RESET SGSN_Test-Gb1-NS1(274)@1c739be12bc2: Creating NSIP provider for "127.0.0.103":21011 [38;5;63m20240820120156699 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-RESET (gprs_ns2.c:1309)[0;m [38;5;57m20240820120156699 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x558fdf4aee10]{UNBLOCKED}: Received Event RX-RESET (gprs_ns2_vc_fsm.c:934)[0;m [38;5;57m20240820120156699 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x558fdf4aee10]{UNBLOCKED}: state_chg to RESET (gprs_ns2_vc_fsm.c:657)[0;m [38;5;57m20240820120156699 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00096) NS-STATUS.ind(bvci=00000): cause=NSE failure, transfer=0, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240820120156699 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 96 became unavailable (gprs_ns.c:54) [38;5;63m20240820120156699 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-RESET-ACK (gprs_ns2_message.c:331)[0;m [38;5;57m20240820120156699 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x558fdf4aee10]{RESET}: state_chg to BLOCKED (gprs_ns2_vc_fsm.c:329)[0;m [38;5;63m20240820120156699 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;57m20240820120156699 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x558fdf4aee10]{BLOCKED}: Starting Tns-alive of 3 seconds (gprs_ns2_vc_fsm.c:177)[0;m -NSVCI97(275)@1c739be12bc2: NSVC 97 State Transition: NSVC_S_WAIT_RESET (2) -> NSVC_S_ALIVE_BLOCKED (3) [38;5;63m20240820120156701 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-ALIVE (gprs_ns2.c:1309)[0;m [38;5;57m20240820120156701 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x558fdf4aee10]{BLOCKED}: Received Event RX-ALIVE (gprs_ns2_vc_fsm.c:957)[0;m [38;5;63m20240820120156701 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-ALIVE-ACK (gprs_ns2_message.c:193)[0;m [38;5;63m20240820120156701 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-UNBLOCK (gprs_ns2.c:1309)[0;m [38;5;57m20240820120156701 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x558fdf4aee10]{BLOCKED}: Received Event RX-UNBLOCK (gprs_ns2_vc_fsm.c:951)[0;m [38;5;63m20240820120156701 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-UNBLOCK-ACK (gprs_ns2_message.c:193)[0;m [38;5;57m20240820120156701 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x558fdf4aee10]{BLOCKED}: state_chg to UNBLOCKED (gprs_ns2_vc_fsm.c:414)[0;m [38;5;57m20240820120156701 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00096) NS-STATUS.ind(bvci=00000): cause=NSE recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240820120156701 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 96 became available (gprs_ns.c:43) [38;5;57m20240820120156701 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00096)-NSVC(00097) NS-STATUS.ind(bvci=00000): cause=NSVC recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:571)[0;m 20240820120156701 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS: indication Unknown prim 2 from NS (gprs_ns.c:57) -NSVCI97(275)@1c739be12bc2: Rx NS-ALIVE-ACK: stopping Tns-alive; starting Tns-test [38;5;63m20240820120156701 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20240820120156701 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x558fdf4aee10]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960)[0;m -NSVCI97(275)@1c739be12bc2: NSVC 97 State Transition: NSVC_S_ALIVE_BLOCKED (3) -> NSVC_S_ALIVE_UNBLOCKED (4) [38;5;57m20240820120156704 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x558fdf4aee10]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m SGSN_Test-Gb0-BSSGP0(271)@1c739be12bc2: BVCI(0) Rx BVC-RESET-ACK SGSN_Test-Gb0-BSSGP0(271)@1c739be12bc2: BVCI(0) State Transition: BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) -> BVC_S_UNBLOCKED (3) SGSN_Test-Gb1-BSSGP1(276)@1c739be12bc2: BVCI(0) State Transition: BVC_S_WAIT_RESET (0) -> BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) SGSN_Test-Gb1-NS1(274)@1c739be12bc2: 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 } [38;5;57m20240820120156712 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x558fdf4aee10]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m [38;5;59m20240820120156712 [1;33mDLBSSGP[0;m[38;5;59m [1;33mNOTICE[0;m[38;5;59m Cell 262-42-13135-0 CI 20960 on BVCI 196 (gprs_bssgp.c:400)[0;m -NSVCI98(279)@1c739be12bc2: NSVC 98 State Transition: NSVC_S_DEAD_BLOCKED (1) -> NSVC_S_DEAD_BLOCKED (1) TC_attach_no_imsi_response-BVCI196(272)@1c739be12bc2: BVCI(196) State Transition: BVC_S_BLOCKED (2) -> BVC_S_UNBLOCKED (3) -NSVCI98(279)@1c739be12bc2: Provider Link came up: sending NS-RESET [38;5;63m20240820120156716 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-RESET (gprs_ns2.c:1309)[0;m [38;5;57m20240820120156716 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x558fdf4b12a0]{UNBLOCKED}: Received Event RX-RESET (gprs_ns2_vc_fsm.c:934)[0;m [38;5;57m20240820120156716 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x558fdf4b12a0]{UNBLOCKED}: state_chg to RESET (gprs_ns2_vc_fsm.c:657)[0;m [38;5;57m20240820120156716 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00097) NS-STATUS.ind(bvci=00000): cause=NSE failure, transfer=0, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240820120156716 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 97 became unavailable (gprs_ns.c:54) [38;5;63m20240820120156716 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-RESET-ACK (gprs_ns2_message.c:331)[0;m [38;5;57m20240820120156716 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x558fdf4b12a0]{RESET}: state_chg to BLOCKED (gprs_ns2_vc_fsm.c:329)[0;m [38;5;63m20240820120156716 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;57m20240820120156716 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x558fdf4b12a0]{BLOCKED}: Starting Tns-alive of 3 seconds (gprs_ns2_vc_fsm.c:177)[0;m -NSVCI98(279)@1c739be12bc2: NSVC 98 State Transition: NSVC_S_WAIT_RESET (2) -> NSVC_S_ALIVE_BLOCKED (3) [38;5;63m20240820120156717 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-ALIVE (gprs_ns2.c:1309)[0;m [38;5;57m20240820120156717 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x558fdf4b12a0]{BLOCKED}: Received Event RX-ALIVE (gprs_ns2_vc_fsm.c:957)[0;m [38;5;63m20240820120156718 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-ALIVE-ACK (gprs_ns2_message.c:193)[0;m [38;5;63m20240820120156718 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-UNBLOCK (gprs_ns2.c:1309)[0;m [38;5;57m20240820120156718 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x558fdf4b12a0]{BLOCKED}: Received Event RX-UNBLOCK (gprs_ns2_vc_fsm.c:951)[0;m [38;5;63m20240820120156718 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-UNBLOCK-ACK (gprs_ns2_message.c:193)[0;m [38;5;57m20240820120156718 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x558fdf4b12a0]{BLOCKED}: state_chg to UNBLOCKED (gprs_ns2_vc_fsm.c:414)[0;m [38;5;57m20240820120156718 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00097) NS-STATUS.ind(bvci=00000): cause=NSE recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240820120156718 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 97 became available (gprs_ns.c:43) [38;5;57m20240820120156718 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00097)-NSVC(00098) NS-STATUS.ind(bvci=00000): cause=NSVC recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:571)[0;m 20240820120156718 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS: indication Unknown prim 2 from NS (gprs_ns.c:57) [38;5;63m20240820120156718 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20240820120156718 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x558fdf4b12a0]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960)[0;m -NSVCI98(279)@1c739be12bc2: Rx NS-ALIVE-ACK: stopping Tns-alive; starting Tns-test -NSVCI98(279)@1c739be12bc2: NSVC 98 State Transition: NSVC_S_ALIVE_BLOCKED (3) -> NSVC_S_ALIVE_UNBLOCKED (4) [38;5;57m20240820120156721 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x558fdf4b12a0]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m SGSN_Test-Gb2-NS2(280)@1c739be12bc2: Creating NSIP provider for "127.0.0.103":21012 SGSN_Test-Gb1-BSSGP1(276)@1c739be12bc2: BVCI(0) Rx BVC-RESET-ACK SGSN_Test-Gb1-BSSGP1(276)@1c739be12bc2: BVCI(0) State Transition: BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) -> BVC_S_UNBLOCKED (3) [38;5;57m20240820120156729 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x558fdf4b12a0]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m [38;5;59m20240820120156729 [1;33mDLBSSGP[0;m[38;5;59m [1;33mNOTICE[0;m[38;5;59m Cell 262-42-13200-0 CI 20961 on BVCI 210 (gprs_bssgp.c:400)[0;m TC_attach_no_imsi_response-BVCI210(278)@1c739be12bc2: BVCI(210) State Transition: BVC_S_BLOCKED (2) -> BVC_S_UNBLOCKED (3) SGSN_Test-Gb2-BSSGP2(281)@1c739be12bc2: BVCI(0) State Transition: BVC_S_WAIT_RESET (0) -> BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) SGSN_Test-Gb2-NS2(280)@1c739be12bc2: 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(284)@1c739be12bc2: NSVC 99 State Transition: NSVC_S_DEAD_BLOCKED (1) -> NSVC_S_DEAD_BLOCKED (1) -NSVCI99(284)@1c739be12bc2: Provider Link came up: sending NS-RESET [38;5;63m20240820120156738 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-RESET (gprs_ns2.c:1309)[0;m [38;5;57m20240820120156738 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x558fdf4b2d00]{UNBLOCKED}: Received Event RX-RESET (gprs_ns2_vc_fsm.c:934)[0;m [38;5;57m20240820120156738 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x558fdf4b2d00]{UNBLOCKED}: state_chg to RESET (gprs_ns2_vc_fsm.c:657)[0;m [38;5;57m20240820120156738 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00098) NS-STATUS.ind(bvci=00000): cause=NSE failure, transfer=0, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240820120156738 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 98 became unavailable (gprs_ns.c:54) [38;5;63m20240820120156738 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-RESET-ACK (gprs_ns2_message.c:331)[0;m [38;5;57m20240820120156738 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x558fdf4b2d00]{RESET}: state_chg to BLOCKED (gprs_ns2_vc_fsm.c:329)[0;m [38;5;63m20240820120156738 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;57m20240820120156738 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x558fdf4b2d00]{BLOCKED}: Starting Tns-alive of 3 seconds (gprs_ns2_vc_fsm.c:177)[0;m -NSVCI99(284)@1c739be12bc2: NSVC 99 State Transition: NSVC_S_WAIT_RESET (2) -> NSVC_S_ALIVE_BLOCKED (3) [38;5;63m20240820120156739 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-ALIVE (gprs_ns2.c:1309)[0;m [38;5;57m20240820120156739 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x558fdf4b2d00]{BLOCKED}: Received Event RX-ALIVE (gprs_ns2_vc_fsm.c:957)[0;m [38;5;63m20240820120156739 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-ALIVE-ACK (gprs_ns2_message.c:193)[0;m [38;5;63m20240820120156739 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-UNBLOCK (gprs_ns2.c:1309)[0;m [38;5;57m20240820120156739 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x558fdf4b2d00]{BLOCKED}: Received Event RX-UNBLOCK (gprs_ns2_vc_fsm.c:951)[0;m [38;5;63m20240820120156739 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-UNBLOCK-ACK (gprs_ns2_message.c:193)[0;m [38;5;57m20240820120156740 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x558fdf4b2d00]{BLOCKED}: state_chg to UNBLOCKED (gprs_ns2_vc_fsm.c:414)[0;m [38;5;57m20240820120156740 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00098) NS-STATUS.ind(bvci=00000): cause=NSE recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240820120156740 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 98 became available (gprs_ns.c:43) [38;5;57m20240820120156740 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00098)-NSVC(00099) NS-STATUS.ind(bvci=00000): cause=NSVC recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:571)[0;m 20240820120156740 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS: indication Unknown prim 2 from NS (gprs_ns.c:57) [38;5;63m20240820120156740 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20240820120156740 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x558fdf4b2d00]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960)[0;m -NSVCI99(284)@1c739be12bc2: Rx NS-ALIVE-ACK: stopping Tns-alive; starting Tns-test -NSVCI99(284)@1c739be12bc2: NSVC 99 State Transition: NSVC_S_ALIVE_BLOCKED (3) -> NSVC_S_ALIVE_UNBLOCKED (4) [38;5;57m20240820120156743 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x558fdf4b2d00]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m SGSN_Test-Gb2-BSSGP2(281)@1c739be12bc2: BVCI(0) Rx BVC-RESET-ACK SGSN_Test-Gb2-BSSGP2(281)@1c739be12bc2: BVCI(0) State Transition: BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) -> BVC_S_UNBLOCKED (3) [38;5;57m20240820120156749 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x558fdf4b2d00]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m [38;5;59m20240820120156749 [1;33mDLBSSGP[0;m[38;5;59m [1;33mNOTICE[0;m[38;5;59m Cell 262-42-13200-0 CI 20962 on BVCI 220 (gprs_bssgp.c:400)[0;m TC_attach_no_imsi_response-BVCI220(283)@1c739be12bc2: BVCI(220) State Transition: BVC_S_BLOCKED (2) -> BVC_S_UNBLOCKED (3) [38;5;39m20240820120157459 [1;33mDLGSUP[0;m[38;5;39m [1;33mNOTICE[0;m[38;5;39m GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74)[0;m [38;5;23m20240820120157459 [1;33mDLINP[0;m[38;5;23m [1;33mNOTICE[0;m[38;5;23m 127.0.0.103:4222 connection done (ipa.c:143)[0;m [38;5;39m20240820120157459 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 UP (gsup_client.c:151)[0;m [38;5;39m20240820120157459 [1;34mDLGSUP[0;m[38;5;39m [1;34mDEBUG[0;m[38;5;39m GSUP sending PING (gsup_client.c:288)[0;m SGSN_Test-GSUP-IPA(285)@1c739be12bc2: Established a new IPA connection (conn_id=2) SGSN_Test-GSUP-IPA(285)@1c739be12bc2: 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) } } } } [38;5;23m20240820120157460 [1;33mDLINP[0;m[38;5;23m [1;33mNOTICE[0;m[38;5;23m received ID_GET for unit ID 0/0/0 (ipaccess.c:897)[0;m [38;5;39m20240820120157461 [1;34mDLGSUP[0;m[38;5;39m [1;34mDEBUG[0;m[38;5;39m GSUP receiving PONG (gsup_client.c:225)[0;m SGSN_Test-GSUP-IPA(285)@1c739be12bc2: CCM Rx:{ msg_type := IPAC_MSGT_PING (0), u := omit } SGSN_Test-GSUP-IPA(285)@1c739be12bc2: CCM Tx:{ msg_type := IPAC_MSGT_PONG (1), u := omit } SGSN_Test-GSUP-IPA(285)@1c739be12bc2: 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(285)@1c739be12bc2: IPA ID 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(285)@1c739be12bc2: CCM Tx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } SGSN_Test-GSUP-IPA(285)@1c739be12bc2: CCM Rx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_attach_no_imsi_response-BVCI196(272)@1c739be12bc2: Adding Client=TC_attach_no_imsi_response(288), IMSI='262420000000035'H, TLLI='D923B82A'O, index=0 SGSN_Test-GSUP(286)@1c739be12bc2: Created GsupExpect[0] for "262420000000035" to be handled at TC_attach_no_imsi_response(288) [38;5;57m20240820120158482 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x558fdf4aee10]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m 20240820120158482 [1;33mDLLC[0;m [1;33mNOTICE[0;m LLME(ffffffff/d923b82a){UNASSIGNED} LLC RX: unknown TLLI 0xd923b82a, creating LLME on the fly (gprs_llc.c:552) 20240820120158482 [1;34mDLLC[0;m [1;34mDEBUG[0;m LLC SAPI=1 C U GEA0 IOV-UI=0x000000 FCS=0x24bf94 CMD=UI DATA (gprs_llc_parse.c:89) [1;33m20240820120158482 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(---/ffffffff) -> GMM ATTACH REQUEST [0;m[1;33mMI(TMSI-0xC0000035) type="Combined GPRS/IMSI attach" [0;m[1;33m (gprs_gmm.c:1266)[0;m [1;33m20240820120158482 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM(gmm_fsm)[0x558fdf4b4450]{Deregistered}: Allocated (fsm.c:456)[0;m [1;33m20240820120158482 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x558fdf4b47e0]{Init}: Allocated (fsm.c:456)[0;m [1;33m20240820120158482 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Gb[0x558fdf4b46b0]{Idle}: Allocated (fsm.c:456)[0;m [1;33m20240820120158482 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Iu[0x558fdf4b4580]{Detached}: Allocated (fsm.c:456)[0;m [1;33m20240820120158482 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM(gmm_fsm)[0x558fdf4b4450]{Deregistered}: Received Event E_GMM_COMMON_PROC_INIT_REQ (gprs_gmm.c:1144)[0;m [1;33m20240820120158482 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM(gmm_fsm)[0x558fdf4b4450]{Deregistered}: state_chg to CommonProcedureInitiated (gprs_gmm_fsm.c:49)[0;m 20240820120158482 [1;33mDLLC[0;m [1;33mNOTICE[0;m LLME(ffffffff/d923b82a){UNASSIGNED} LLGM Assign pre (d923b82a => d64c93cc) (gprs_llc.c:1079) 20240820120158482 [1;33mDLLC[0;m [1;33mNOTICE[0;m LLME(d923b82a/d64c93cc){ASSIGNED} LLGM Assign post (d923b82a => d64c93cc) (gprs_llc.c:1125) [1;33m20240820120158482 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x558fdf4b47e0]{Init}: Received Event E_ATTACH_REQ_RECV (gprs_gmm.c:1370)[0;m [1;33m20240820120158482 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x558fdf4b47e0]{Init}: state_chg to CheckIdentity (gprs_gmm_attach.c:52)[0;m [1;33m20240820120158482 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(/d64c93cc) <- GMM IDENTITY REQUEST: mi_type=IMEI (gprs_gmm.c:431)[0;m [38;5;57m20240820120158490 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x558fdf4aee10]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m 20240820120158490 [1;34mDLLC[0;m [1;34mDEBUG[0;m LLC SAPI=1 C U GEA0 IOV-UI=0x000000 FCS=0x612fca CMD=UI DATA (gprs_llc_parse.c:89) [1;33m20240820120158490 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Gb(3642996778)[0x558fdf4b46b0]{Idle}: Received Event E_MM_PDU_RECEPTION (gprs_gmm.c:2333)[0;m [1;33m20240820120158490 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(/d64c93cc) -> GMM IDENTITY RESPONSE: MI=IMEI-499990000000350 (gprs_gmm.c:1084)[0;m [1;33m20240820120158490 [1;33mDMM[0;m[1;33m [1;33mNOTICE[0;m[1;33m MM(/d64c93cc) Stopping *inactive* MM timer 3370 (gprs_gmm.c:115)[0;m [1;33m20240820120158490 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x558fdf4b47e0]{CheckIdentity}: Received Event E_IDEN_RESP_RECV (gprs_gmm.c:1128)[0;m [1;33m20240820120158490 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x558fdf4b47e0]{CheckIdentity}: state_chg to CheckIdentity (gprs_gmm_attach.c:113)[0;m [1;33m20240820120158491 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(/d64c93cc) <- GMM IDENTITY REQUEST: mi_type=IMSI (gprs_gmm.c:431)[0;m 20240820120202437 [1;34mDGPRS[0;m [1;34mDEBUG[0;m Checking for inactive LLMEs, time = 26683521 (sgsn.c:131) [1;33m20240820120204491 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x558fdf4b47e0]{CheckIdentity}: Timeout of T3370 (fsm.c:317)[0;m [1;33m20240820120204491 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(/d64c93cc) <- GMM IDENTITY REQUEST: mi_type=IMSI (gprs_gmm.c:431)[0;m [1;33m20240820120210492 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x558fdf4b47e0]{CheckIdentity}: Timeout of T3370 (fsm.c:317)[0;m [1;33m20240820120210492 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(/d64c93cc) <- GMM IDENTITY REQUEST: mi_type=IMSI (gprs_gmm.c:431)[0;m [1;91m[testenv][generic] stp crashed![0m Error: container 1c739be12bc2f8a482dd66c05d277611429f392a20a4bb4a23b7f966ba5b93d9 does not exist in database: no such container [1;91m[testenv] podman container crashed![0m [1;34m[testenv][generic] Stopping testsuite (590140)[0m [1;34m[testenv][generic] Logs saved to: https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/169/artifa… [0m Build step 'Execute shell' marked build as failure Recording test results [Checks API] No suitable checks publisher found.

1 0

Jenkins build is back to stable : ttcn3-hlr-test-asan #74
by jenkins＠lists.osmocom.org 19 Aug '24

19 Aug '24

See <https://jenkins.osmocom.org/jenkins/job/ttcn3-hlr-test-asan/74/display/redi…>

1 0

Build failed in Jenkins: master-osmo-msc » --disable-iu,0,a3=default,a4=default,osmocom-master #45069
by jenkins＠lists.osmocom.org 19 Aug '24

19 Aug '24

See <https://jenkins.osmocom.org/jenkins/job/master-osmo-msc/IU=--disable-iu,WIT…> Changes: ------------------------------------------ [...truncated 636.60 KB...] logging level asci notice logging level lglobal notice logging level llapd notice logging level linp notice logging level lmux notice logging level lmi notice logging level lmib notice logging level lsms notice logging level lctrl notice logging level lgtp notice logging level lstats notice logging level lgsup notice logging level loap notice logging level lss7 notice logging level lsccp notice logging level lsua notice logging level lm3ua notice logging level lmgcp notice logging level ljibuf notice logging level lrspro notice logging level lns notice logging level lbssgp notice logging level lnsdata notice logging level lnssignal notice logging level liuup notice logging level lpfcp notice logging level lcsn1 notice logging level lio notice ! stats interval 5 ! line vty no login ! cs7 instance 0 point-code 0.23.1 network network country code 001 mobile network code 01 short name OsmoMSC long name OsmoMSC encryption a5 0 encryption uea 1 2 authentication optional rrlp mode none mm info 1 mgw 0 local-port 2728 remote-ip 127.0.0.1 remote-port 2427 msc mncc internal mncc guard-timeout 180 ncss guard-timeout 30 assign-tmsi cs7-instance-a 0 auth-tuple-max-reuse-count 3 auth-tuple-reuse-on-error 1 mncc-int default-codec tch-f fr default-codec tch-h hr smpp local-tcp-port 2775 policy closed no smpp-first hlr remote-ip 127.0.0.1 remote-port 4222 ipa-name unnamed-MSC sgs local-port 29118 local-ip 0.0.0.0 vlr-name vlr.example.net smsc queue max-pending 20 queue max-failure 1 database delete-delivered 1 database delete-expired 1 validity-period minimum 1 validity-period default 10080 asci disable gcr end [1;33mDMSC[0;m [1;33mNOTICE[0;m Terminating due to signal 15 (msc_main.c:286) full talloc report on 'osmo_msc' (total 19638 bytes in 94 blocks) struct osmo_ss7_instance contains 5113 bytes in 38 blocks (ref 0) 0x562b809c4970 struct osmo_sccp_instance contains 858 bytes in 6 blocks (ref 0) 0x562b80b0bed0 struct osmo_sccp_user contains 90 bytes in 2 blocks (ref 0) 0x562b80b14ae0 OsmoMSC-A contains 10 bytes in 1 blocks (ref 0) 0x562b80b23160 struct osmo_sccp_user contains 96 bytes in 2 blocks (ref 0) 0x562b80b07b60 SCCP Management contains 16 bytes in 1 blocks (ref 0) 0x562b80b230e0 sccp_user.c:241 contains 560 bytes in 1 blocks (ref 0) 0x562b80b22e40 struct osmo_ss7_asp contains 2958 bytes in 19 blocks (ref 0) 0x562b809c28d0 struct osmo_fsm_inst contains 367 bytes in 4 blocks (ref 0) 0x562b80b22bf0 struct xua_asp_fsm_priv contains 104 bytes in 1 blocks (ref 0) 0x562b80b07040 XUA_ASP(asp-clnt-OsmoMSC-A)[0x562b80b22bf0] contains 44 bytes in 1 blocks (ref 0) 0x562b80b22da0 asp-clnt-OsmoMSC-A contains 19 bytes in 1 blocks (ref 0) 0x562b80b22d20 struct osmo_stream_cli contains 951 bytes in 4 blocks (ref 0) 0x562b80b227f0 localhost contains 10 bytes in 1 blocks (ref 0) 0x562b80b1cef0 localhost contains 10 bytes in 1 blocks (ref 0) 0x562b80b18c20 asp-clnt-OsmoMSC-A contains 19 bytes in 1 blocks (ref 0) 0x562b80b14e30 struct osmo_fsm_inst contains 278 bytes in 4 blocks (ref 0) 0x562b80b225a0 struct lm_fsm_priv contains 8 bytes in 1 blocks (ref 0) 0x562b80b075c0 xua_default_lm(asp-clnt-OsmoMSC-A)[0x562b80b225a0] contains 51 bytes in 1 blocks (ref 0) 0x562b80b22750 asp-clnt-OsmoMSC-A contains 19 bytes in 1 blocks (ref 0) 0x562b80b226d0 localhost contains 10 bytes in 1 blocks (ref 0) 0x562b80aea860 localhost contains 10 bytes in 1 blocks (ref 0) 0x562b80b18a80 osmo_ss7_asp.c:561 contains 280 bytes in 1 blocks (ref 0) 0x562b80aea6e0 asp-clnt-OsmoMSC-A contains 19 bytes in 1 blocks (ref 0) 0x562b80aea660 rate_ctr.c:233 contains 299 bytes in 2 blocks (ref 0) 0x562b80aea4e0 asp-clnt-OsmoMSC-A contains 19 bytes in 1 blocks (ref 0) 0x562b80b14c00 struct osmo_ss7_as contains 856 bytes in 8 blocks (ref 0) 0x562b8099efa0 struct osmo_fsm_inst contains 372 bytes in 4 blocks (ref 0) 0x562b80af07c0 struct xua_as_fsm_priv contains 112 bytes in 1 blocks (ref 0) 0x562b80b10f70 XUA_AS(as-clnt-OsmoMSC-A)[0x562b80af07c0] contains 42 bytes in 1 blocks (ref 0) 0x562b80af08f0 as-clnt-OsmoMSC-A contains 18 bytes in 1 blocks (ref 0) 0x562b80b0c2d0 as-clnt-OsmoMSC-A contains 18 bytes in 1 blocks (ref 0) 0x562b80b07860 rate_ctr.c:233 contains 218 bytes in 2 blocks (ref 0) 0x562b80af0690 as-clnt-OsmoMSC-A contains 18 bytes in 1 blocks (ref 0) 0x562b80b119f0 struct osmo_ss7_route_table contains 145 bytes in 4 blocks (ref 0) 0x562b80b096a0 struct osmo_ss7_route contains 82 bytes in 2 blocks (ref 0) 0x562b80b06f60 as-clnt-OsmoMSC-A contains 18 bytes in 1 blocks (ref 0) 0x562b80b07920 system contains 7 bytes in 1 blocks (ref 0) 0x562b80b0c430 telnet_connection contains 1 bytes in 1 blocks (ref 0) 0x562b80aeb920 struct osmo_stream_srv_link contains 1920 bytes in 2 blocks (ref 0) 0x562b80ae9a00 0.0.0.0 contains 8 bytes in 1 blocks (ref 0) 0x562b80aea1e0 struct sgs_state contains 376 bytes in 1 blocks (ref 0) 0x562b80ae9820 struct smsc contains 152 bytes in 1 blocks (ref 0) 0x562b8099c980 sms.db contains 7 bytes in 1 blocks (ref 0) 0x562b80a04620 struct sms_queue_config contains 32 bytes in 1 blocks (ref 0) 0x562b80a04590 struct gsm_network contains 11227 bytes in 31 blocks (ref 0) 0x562b8099f1a0 struct sccp_ran_inst contains 152 bytes in 1 blocks (ref 0) 0x562b80b07c20 struct gsm_sms_queue contains 776 bytes in 4 blocks (ref 0) 0x562b809c41f0 rate_ctr.c:233 contains 440 bytes in 1 blocks (ref 0) 0x562b80aec770 stat_item.c:195 contains 104 bytes in 2 blocks (ref 0) 0x562b80aeb290 struct osmo_stat_item contains 56 bytes in 1 blocks (ref 0) 0x562b80aeb330 struct gsup_client_mux contains 682 bytes in 6 blocks (ref 0) 0x562b80aeb050 struct osmo_gsup_client contains 514 bytes in 4 blocks (ref 0) 0x562b809e7660 struct osmo_fd contains 48 bytes in 1 blocks (ref 0) 0x562b80aeb120 struct ipa_client_conn contains 202 bytes in 2 blocks (ref 0) 0x562b809a1510 127.0.0.1 contains 10 bytes in 1 blocks (ref 0) 0x562b80aeb1c0 struct ipaccess_unit contains 64 bytes in 1 blocks (ref 0) 0x562b80aebc40 struct ctrl_handle contains 88 bytes in 1 blocks (ref 0) 0x562b80aeae30 127.0.0.1 contains 10 bytes in 1 blocks (ref 0) 0x562b80aebe60 struct vlr_instance contains 2496 bytes in 5 blocks (ref 0) 0x562b8099da50 rate_ctr.c:233 contains 2040 bytes in 1 blocks (ref 0) 0x562b80ad3d80 stat_item.c:195 contains 168 bytes in 2 blocks (ref 0) 0x562b80ad3c00 struct osmo_stat_item contains 112 bytes in 1 blocks (ref 0) 0x562b80ad3ca0 struct osmo_nri_ranges contains 16 bytes in 1 blocks (ref 0) 0x562b80ad3b80 struct mgcp_client_conf contains 1088 bytes in 1 blocks (ref 0) 0x562b80a040e0 struct mgcp_client_pool contains 2877 bytes in 7 blocks (ref 0) 0x562b80a04050 struct mgcp_client_pool_member contains 2716 bytes in 4 blocks (ref 0) 0x562b80aec070 struct mgcp_client contains 1580 bytes in 3 blocks (ref 0) 0x562b80af0110 struct osmo_io_fd contains 284 bytes in 2 blocks (ref 0) 0x562b809a1ba0 r=127.0.0.1:2427<->l=127.0.0.1:2728 contains 36 bytes in 1 blocks (ref 0) 0x562b80b07d60 struct cmd_node contains 121 bytes in 2 blocks (ref 0) 0x562b8099f970 %s(config-mgw)# contains 17 bytes in 1 blocks (ref 0) 0x562b80a26260 127.0.0.1 contains 10 bytes in 1 blocks (ref 0) 0x562b80a03180 stat_item.c:195 contains 168 bytes in 2 blocks (ref 0) 0x562b80a03ed0 struct osmo_stat_item contains 112 bytes in 1 blocks (ref 0) 0x562b8099fd10 rate_ctr.c:233 contains 2520 bytes in 1 blocks (ref 0) 0x562b80a03490 struct sched_vty_opts contains 72 bytes in 1 blocks (ref 0) 0x562b809f0e30 utils.c:386 contains 203 bytes in 1 blocks (ref 0) 0x562b80928a10 utils.c:386 contains 46 bytes in 1 blocks (ref 0) 0x562b80928970 utils.c:386 contains 165 bytes in 1 blocks (ref 0) 0x562b80928860 utils.c:386 contains 43 bytes in 1 blocks (ref 0) 0x562b809287c0 transaction contains 0 bytes in 1 blocks (ref 0) 0x562b80904a70 gsm_call contains 0 bytes in 1 blocks (ref 0) 0x562b80904a00 sms contains 0 bytes in 1 blocks (ref 0) 0x562b80904990 osmo_signal contains 280 bytes in 8 blocks (ref 0) 0x562b80904920 struct signal_handler contains 40 bytes in 1 blocks (ref 0) 0x562b80b0c4a0 struct signal_handler contains 40 bytes in 1 blocks (ref 0) 0x562b80af0d70 struct signal_handler contains 40 bytes in 1 blocks (ref 0) 0x562b80aeb890 struct signal_handler contains 40 bytes in 1 blocks (ref 0) 0x562b80aeb990 struct signal_handler contains 40 bytes in 1 blocks (ref 0) 0x562b80aebdd0 struct signal_handler contains 40 bytes in 1 blocks (ref 0) 0x562b80aebf60 struct signal_handler contains 40 bytes in 1 blocks (ref 0) 0x562b80a9ab40 msgb contains 0 bytes in 1 blocks (ref 0) 0x562b809048b0 full talloc report on 'null_context' (total 24 bytes in 2 blocks) struct lookup_helper contains 24 bytes in 1 blocks (ref 0) 0x562b80aeb700 signal 15 received Terminating took 0.897s RESULTS: pass: ../../../tests/test_neighbor_ident.vty pass: ../../../tests/test_nodes.vty rm -f ./sms.db* make[8]: Leaving directory '/build/osmo-msc-1.12.0/_build/sub/tests' make[7]: Leaving directory '/build/osmo-msc-1.12.0/_build/sub/tests' make ctrl-test make[7]: Entering directory '/build/osmo-msc-1.12.0/_build/sub/tests' make ctrl-python-test make[8]: Entering directory '/build/osmo-msc-1.12.0/_build/sub/tests' ../../../tests/ctrl_test_runner.py -w /build/osmo-msc-1.12.0/_build/sub -v testRateCounters (__main__.TestCtrlMSC.testRateCounters) ... ERROR ====================================================================== ERROR: testRateCounters (__main__.TestCtrlMSC.testRateCounters) ---------------------------------------------------------------------- Traceback (most recent call last): File "/build/osmo-msc-1.12.0/_build/sub/tests/../../../tests/ctrl_test_runner.py", line 69, in tearDown raise Exception("Process returned %d" % rc) Exception: Process returned -6 ---------------------------------------------------------------------- Ran 1 test in 2.169s FAILED (errors=1) confpath /build/osmo-msc-1.12.0/tests/.., workdir /build/osmo-msc-1.12.0/_build/sub Running tests for specific control commands Opening /dev/null Launching: PWD=/build/osmo-msc-1.12.0/_build/sub './src/osmo-msc/osmo-msc' '-c' '/build/osmo-msc-1.12.0/tests/../doc/examples/osmo-msc/osmo-msc.cfg' Connecting to host 127.0.0.1:4255 Sending "GET 1000 rate_ctr.*" Got message: b'ERROR 1000 GET variable contains invalid characters' Decoded replies: {1000: {'mtype': b'ERROR', 'id': 1000, 'var': b'GET', 'value': b'variable contains invalid characters'}} Process returned code: -6 make[8]: *** [Makefile:749: ctrl-python-test] Error 1 make[8]: Leaving directory '/build/osmo-msc-1.12.0/_build/sub/tests' make[7]: *** [Makefile:760: ctrl-test] Error 2 make[7]: Leaving directory '/build/osmo-msc-1.12.0/_build/sub/tests' make[6]: Leaving directory '/build/osmo-msc-1.12.0/_build/sub/tests' make[6]: *** [Makefile:716: python-tests] Error 2 make[5]: *** [Makefile:769: check-local] Error 2 make[5]: Leaving directory '/build/osmo-msc-1.12.0/_build/sub/tests' make[4]: *** [Makefile:574: check-am] Error 2 make[4]: Leaving directory '/build/osmo-msc-1.12.0/_build/sub/tests' make[3]: *** [Makefile:424: check-recursive] Error 1 make[3]: Leaving directory '/build/osmo-msc-1.12.0/_build/sub/tests' make[2]: Leaving directory '/build/osmo-msc-1.12.0/_build/sub' make[2]: *** [Makefile:473: check-recursive] Error 1 make[1]: Leaving directory '/build/osmo-msc-1.12.0/_build/sub' make[1]: *** [Makefile:772: check] Error 2 make: *** [Makefile:692: distcheck] Error 1 + exit_tar_workspace + '[' 1 = 1 ']' + tar -cJf /tmp/workspace.tar.xz /build tar: Removing leading `/' from member names + mv /tmp/workspace.tar.xz /build + cat-testlogs.sh Build step 'Execute shell' marked build as failure $ ssh-agent -k unset SSH_AUTH_SOCK; unset SSH_AGENT_PID; echo Agent pid 2913252 killed; [ssh-agent] Stopped. Archiving artifacts

1 1

Jenkins build became unstable: ttcn3-epdg-test #313
by jenkins＠lists.osmocom.org 18 Aug '24

18 Aug '24

See <https://jenkins.osmocom.org/jenkins/job/ttcn3-epdg-test/313/display/redirect>

1 1

Jenkins build became unstable: ttcn3-sgsn-test-sns-latest #116
by jenkins＠lists.osmocom.org 17 Aug '24

17 Aug '24

See <https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-sns-latest/116/disp…>

1 1

Jenkins build became unstable: ttcn3-mme-test-ogs #410
by jenkins＠lists.osmocom.org 17 Aug '24

17 Aug '24

See <https://jenkins.osmocom.org/jenkins/job/ttcn3-mme-test-ogs/410/display/redi…>

1 0

Build failed in Jenkins: ttcn3-sgsn-test-asan #74
by jenkins＠lists.osmocom.org 16 Aug '24

16 Aug '24

See <https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-asan/74/display/red…> 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.13 MB...] [38;5;63m20240816124634370 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-ALIVE-ACK (gprs_ns2_message.c:193)[0;m [38;5;63m20240816124634370 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-UNBLOCK (gprs_ns2.c:1309)[0;m [38;5;57m20240816124634370 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x612000004ba0]{BLOCKED}: Received Event RX-UNBLOCK (gprs_ns2_vc_fsm.c:951)[0;m [38;5;63m20240816124634370 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-UNBLOCK-ACK (gprs_ns2_message.c:193)[0;m [38;5;57m20240816124634370 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x612000004ba0]{BLOCKED}: state_chg to UNBLOCKED (gprs_ns2_vc_fsm.c:414)[0;m [38;5;57m20240816124634370 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00096) NS-STATUS.ind(bvci=00000): cause=NSE recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240816124634370 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 96 became available (gprs_ns.c:43) [38;5;57m20240816124634370 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00096)-NSVC(00097) NS-STATUS.ind(bvci=00000): cause=NSVC recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:571)[0;m 20240816124634370 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS: indication Unknown prim 2 from NS (gprs_ns.c:57) [38;5;63m20240816124634370 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m -NSVCI97(350)@bb9044106d99: Rx NS-ALIVE-ACK: stopping Tns-alive; starting Tns-test [38;5;57m20240816124634370 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x612000004ba0]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960)[0;m -NSVCI97(350)@bb9044106d99: NSVC 97 State Transition: NSVC_S_ALIVE_BLOCKED (3) -> NSVC_S_ALIVE_UNBLOCKED (4) [38;5;57m20240816124634373 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x612000004ba0]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m SGSN_Test-Gb0-BSSGP0(347)@bb9044106d99: BVCI(0) Rx BVC-RESET-ACK SGSN_Test-Gb0-BSSGP0(347)@bb9044106d99: BVCI(0) State Transition: BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) -> BVC_S_UNBLOCKED (3) SGSN_Test-Gb1-NS1(351)@bb9044106d99: Creating NSIP provider for "127.0.0.103":21011 [38;5;57m20240816124634380 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x612000004ba0]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m [38;5;59m20240816124634380 [1;33mDLBSSGP[0;m[38;5;59m [1;33mNOTICE[0;m[38;5;59m Cell 262-42-13135-0 CI 20960 on BVCI 196 (gprs_bssgp.c:400)[0;m TC_attach_check_complete_resend-BVCI196(349)@bb9044106d99: BVCI(196) State Transition: BVC_S_BLOCKED (2) -> BVC_S_UNBLOCKED (3) SGSN_Test-Gb1-BSSGP1(352)@bb9044106d99: BVCI(0) State Transition: BVC_S_WAIT_RESET (0) -> BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) SGSN_Test-Gb1-NS1(351)@bb9044106d99: 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(355)@bb9044106d99: NSVC 98 State Transition: NSVC_S_DEAD_BLOCKED (1) -> NSVC_S_DEAD_BLOCKED (1) -NSVCI98(355)@bb9044106d99: Provider Link came up: sending NS-RESET [38;5;63m20240816124634402 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-RESET (gprs_ns2.c:1309)[0;m [38;5;57m20240816124634402 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x612000004d20]{UNBLOCKED}: Received Event RX-RESET (gprs_ns2_vc_fsm.c:934)[0;m [38;5;57m20240816124634402 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x612000004d20]{UNBLOCKED}: state_chg to RESET (gprs_ns2_vc_fsm.c:657)[0;m [38;5;57m20240816124634402 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00097) NS-STATUS.ind(bvci=00000): cause=NSE failure, transfer=0, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240816124634402 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 97 became unavailable (gprs_ns.c:54) [38;5;63m20240816124634402 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-RESET-ACK (gprs_ns2_message.c:331)[0;m [38;5;57m20240816124634403 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x612000004d20]{RESET}: state_chg to BLOCKED (gprs_ns2_vc_fsm.c:329)[0;m [38;5;63m20240816124634403 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;57m20240816124634403 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x612000004d20]{BLOCKED}: Starting Tns-alive of 3 seconds (gprs_ns2_vc_fsm.c:177)[0;m -NSVCI98(355)@bb9044106d99: NSVC 98 State Transition: NSVC_S_WAIT_RESET (2) -> NSVC_S_ALIVE_BLOCKED (3) [38;5;63m20240816124634404 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-ALIVE (gprs_ns2.c:1309)[0;m [38;5;57m20240816124634404 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x612000004d20]{BLOCKED}: Received Event RX-ALIVE (gprs_ns2_vc_fsm.c:957)[0;m [38;5;63m20240816124634404 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-ALIVE-ACK (gprs_ns2_message.c:193)[0;m [38;5;63m20240816124634404 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-UNBLOCK (gprs_ns2.c:1309)[0;m [38;5;57m20240816124634404 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x612000004d20]{BLOCKED}: Received Event RX-UNBLOCK (gprs_ns2_vc_fsm.c:951)[0;m [38;5;63m20240816124634404 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-UNBLOCK-ACK (gprs_ns2_message.c:193)[0;m [38;5;57m20240816124634404 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x612000004d20]{BLOCKED}: state_chg to UNBLOCKED (gprs_ns2_vc_fsm.c:414)[0;m [38;5;57m20240816124634404 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00097) NS-STATUS.ind(bvci=00000): cause=NSE recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240816124634404 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 97 became available (gprs_ns.c:43) [38;5;57m20240816124634404 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00097)-NSVC(00098) NS-STATUS.ind(bvci=00000): cause=NSVC recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:571)[0;m 20240816124634404 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS: indication Unknown prim 2 from NS (gprs_ns.c:57) [38;5;63m20240816124634404 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20240816124634404 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x612000004d20]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960)[0;m -NSVCI98(355)@bb9044106d99: Rx NS-ALIVE-ACK: stopping Tns-alive; starting Tns-test -NSVCI98(355)@bb9044106d99: NSVC 98 State Transition: NSVC_S_ALIVE_BLOCKED (3) -> NSVC_S_ALIVE_UNBLOCKED (4) [38;5;57m20240816124634407 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x612000004d20]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m SGSN_Test-Gb1-BSSGP1(352)@bb9044106d99: BVCI(0) Rx BVC-RESET-ACK SGSN_Test-Gb1-BSSGP1(352)@bb9044106d99: BVCI(0) State Transition: BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) -> BVC_S_UNBLOCKED (3) SGSN_Test-Gb2-NS2(356)@bb9044106d99: Creating NSIP provider for "127.0.0.103":21012 [38;5;57m20240816124634414 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x612000004d20]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m [38;5;59m20240816124634414 [1;33mDLBSSGP[0;m[38;5;59m [1;33mNOTICE[0;m[38;5;59m Cell 262-42-13200-0 CI 20961 on BVCI 210 (gprs_bssgp.c:400)[0;m TC_attach_check_complete_resend-BVCI210(354)@bb9044106d99: BVCI(210) State Transition: BVC_S_BLOCKED (2) -> BVC_S_UNBLOCKED (3) SGSN_Test-Gb2-BSSGP2(357)@bb9044106d99: BVCI(0) State Transition: BVC_S_WAIT_RESET (0) -> BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) SGSN_Test-Gb2-NS2(356)@bb9044106d99: 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(360)@bb9044106d99: NSVC 99 State Transition: NSVC_S_DEAD_BLOCKED (1) -> NSVC_S_DEAD_BLOCKED (1) -NSVCI99(360)@bb9044106d99: Provider Link came up: sending NS-RESET [38;5;63m20240816124634439 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-RESET (gprs_ns2.c:1309)[0;m [38;5;57m20240816124634439 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x612000004ea0]{UNBLOCKED}: Received Event RX-RESET (gprs_ns2_vc_fsm.c:934)[0;m [38;5;57m20240816124634439 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x612000004ea0]{UNBLOCKED}: state_chg to RESET (gprs_ns2_vc_fsm.c:657)[0;m [38;5;57m20240816124634440 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00098) NS-STATUS.ind(bvci=00000): cause=NSE failure, transfer=0, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240816124634440 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 98 became unavailable (gprs_ns.c:54) [38;5;63m20240816124634440 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-RESET-ACK (gprs_ns2_message.c:331)[0;m [38;5;57m20240816124634440 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x612000004ea0]{RESET}: state_chg to BLOCKED (gprs_ns2_vc_fsm.c:329)[0;m [38;5;63m20240816124634440 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;57m20240816124634440 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x612000004ea0]{BLOCKED}: Starting Tns-alive of 3 seconds (gprs_ns2_vc_fsm.c:177)[0;m -NSVCI99(360)@bb9044106d99: NSVC 99 State Transition: NSVC_S_WAIT_RESET (2) -> NSVC_S_ALIVE_BLOCKED (3) [38;5;63m20240816124634441 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-ALIVE (gprs_ns2.c:1309)[0;m [38;5;57m20240816124634441 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x612000004ea0]{BLOCKED}: Received Event RX-ALIVE (gprs_ns2_vc_fsm.c:957)[0;m [38;5;63m20240816124634441 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-ALIVE-ACK (gprs_ns2_message.c:193)[0;m [38;5;63m20240816124634441 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-UNBLOCK (gprs_ns2.c:1309)[0;m [38;5;57m20240816124634441 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x612000004ea0]{BLOCKED}: Received Event RX-UNBLOCK (gprs_ns2_vc_fsm.c:951)[0;m [38;5;63m20240816124634441 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-UNBLOCK-ACK (gprs_ns2_message.c:193)[0;m [38;5;57m20240816124634441 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x612000004ea0]{BLOCKED}: state_chg to UNBLOCKED (gprs_ns2_vc_fsm.c:414)[0;m [38;5;57m20240816124634441 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00098) NS-STATUS.ind(bvci=00000): cause=NSE recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240816124634441 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 98 became available (gprs_ns.c:43) [38;5;57m20240816124634441 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00098)-NSVC(00099) NS-STATUS.ind(bvci=00000): cause=NSVC recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:571)[0;m 20240816124634441 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS: indication Unknown prim 2 from NS (gprs_ns.c:57) [38;5;63m20240816124634442 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20240816124634442 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x612000004ea0]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960)[0;m -NSVCI99(360)@bb9044106d99: Rx NS-ALIVE-ACK: stopping Tns-alive; starting Tns-test -NSVCI99(360)@bb9044106d99: NSVC 99 State Transition: NSVC_S_ALIVE_BLOCKED (3) -> NSVC_S_ALIVE_UNBLOCKED (4) [38;5;57m20240816124634444 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x612000004ea0]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m SGSN_Test-Gb2-BSSGP2(357)@bb9044106d99: BVCI(0) Rx BVC-RESET-ACK SGSN_Test-Gb2-BSSGP2(357)@bb9044106d99: BVCI(0) State Transition: BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) -> BVC_S_UNBLOCKED (3) [38;5;57m20240816124634451 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x612000004ea0]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m [38;5;59m20240816124634452 [1;33mDLBSSGP[0;m[38;5;59m [1;33mNOTICE[0;m[38;5;59m Cell 262-42-13200-0 CI 20962 on BVCI 220 (gprs_bssgp.c:400)[0;m TC_attach_check_complete_resend-BVCI220(359)@bb9044106d99: BVCI(220) State Transition: BVC_S_BLOCKED (2) -> BVC_S_UNBLOCKED (3) [38;5;39m20240816124635195 [1;33mDLGSUP[0;m[38;5;39m [1;33mNOTICE[0;m[38;5;39m GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74)[0;m [38;5;23m20240816124635195 [1;33mDLINP[0;m[38;5;23m [1;33mNOTICE[0;m[38;5;23m 127.0.0.103:4222 connection done (ipa.c:143)[0;m [38;5;39m20240816124635195 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 UP (gsup_client.c:151)[0;m [38;5;39m20240816124635195 [1;34mDLGSUP[0;m[38;5;39m [1;34mDEBUG[0;m[38;5;39m GSUP sending PING (gsup_client.c:288)[0;m SGSN_Test-GSUP-IPA(361)@bb9044106d99: Established a new IPA connection (conn_id=2) SGSN_Test-GSUP-IPA(361)@bb9044106d99: 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) } } } } [38;5;23m20240816124635198 [1;33mDLINP[0;m[38;5;23m [1;33mNOTICE[0;m[38;5;23m received ID_GET for unit ID 0/0/0 (ipaccess.c:897)[0;m SGSN_Test-GSUP-IPA(361)@bb9044106d99: CCM Rx:{ msg_type := IPAC_MSGT_PING (0), u := omit } SGSN_Test-GSUP-IPA(361)@bb9044106d99: CCM Tx:{ msg_type := IPAC_MSGT_PONG (1), u := omit } [38;5;39m20240816124635198 [1;34mDLGSUP[0;m[38;5;39m [1;34mDEBUG[0;m[38;5;39m GSUP receiving PONG (gsup_client.c:225)[0;m SGSN_Test-GSUP-IPA(361)@bb9044106d99: 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(361)@bb9044106d99: IPA ID 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(361)@bb9044106d99: CCM Tx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } SGSN_Test-GSUP-IPA(361)@bb9044106d99: CCM Rx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_attach_check_complete_resend-BVCI196(349)@bb9044106d99: Adding Client=TC_attach_check_complete_resend(364), IMSI='262420000000036'H, TLLI='CFF8BD92'O, index=0 SGSN_Test-GSUP(362)@bb9044106d99: Created GsupExpect[0] for "262420000000036" to be handled at TC_attach_check_complete_resend(364) TC_attach_check_complete_resend(364)@bb9044106d99: GSUP sends only 2G auth tuple{ tag := OSMO_GSUP_AUTH_TUPLE_IE (3), len := 0, val := { auth_tuple := { { tag := OSMO_GSUP_RAND_IE (32), len := 0, val := { rand := 'E8E74F960D6B1406DCC79399E1578473'O } }, { tag := OSMO_GSUP_SRES_IE (33), len := 0, val := { sres := 'FDB364BD'O } }, { tag := OSMO_GSUP_KC_IE (34), len := 0, val := { kc := '980F0C14A1B7E70D'O } } } } } [38;5;57m20240816124636244 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x612000004ba0]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m 20240816124636244 [1;33mDLLC[0;m [1;33mNOTICE[0;m LLME(ffffffff/cff8bd92){UNASSIGNED} LLC RX: unknown TLLI 0xcff8bd92, creating LLME on the fly (gprs_llc.c:552) 20240816124636244 [1;34mDLLC[0;m [1;34mDEBUG[0;m LLC SAPI=1 C U GEA0 IOV-UI=0x000000 FCS=0x24bf94 CMD=UI DATA (gprs_llc_parse.c:89) [1;33m20240816124636244 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(---/ffffffff) -> GMM ATTACH REQUEST [0;m[1;33mMI(IMSI-262420000000036) type="Combined GPRS/IMSI attach" [0;m[1;33m (gprs_gmm.c:1266)[0;m [1;33m20240816124636244 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM(gmm_fsm)[0x6120000108a0]{Deregistered}: Allocated (fsm.c:456)[0;m [1;33m20240816124636244 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{Init}: Allocated (fsm.c:456)[0;m [1;33m20240816124636244 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Gb[0x612000010ba0]{Idle}: Allocated (fsm.c:456)[0;m [1;33m20240816124636244 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Iu[0x612000010d20]{Detached}: Allocated (fsm.c:456)[0;m [1;33m20240816124636244 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM(gmm_fsm)[0x6120000108a0]{Deregistered}: Received Event E_GMM_COMMON_PROC_INIT_REQ (gprs_gmm.c:1144)[0;m [1;33m20240816124636244 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM(gmm_fsm)[0x6120000108a0]{Deregistered}: state_chg to CommonProcedureInitiated (gprs_gmm_fsm.c:49)[0;m 20240816124636244 [1;33mDLLC[0;m [1;33mNOTICE[0;m LLME(ffffffff/cff8bd92){UNASSIGNED} LLGM Assign pre (cff8bd92 => e7e27a3f) (gprs_llc.c:1079) 20240816124636244 [1;33mDLLC[0;m [1;33mNOTICE[0;m LLME(cff8bd92/e7e27a3f){ASSIGNED} LLGM Assign post (cff8bd92 => e7e27a3f) (gprs_llc.c:1125) [1;33m20240816124636244 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{Init}: Received Event E_ATTACH_REQ_RECV (gprs_gmm.c:1370)[0;m [1;33m20240816124636244 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{Init}: state_chg to CheckIdentity (gprs_gmm_attach.c:52)[0;m [1;33m20240816124636245 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000036/e7e27a3f) <- GMM IDENTITY REQUEST: mi_type=IMEI (gprs_gmm.c:431)[0;m [38;5;57m20240816124636255 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x612000004ba0]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m 20240816124636255 [1;34mDLLC[0;m [1;34mDEBUG[0;m LLC SAPI=1 C U GEA0 IOV-UI=0x000000 FCS=0x612fca CMD=UI DATA (gprs_llc_parse.c:89) [1;33m20240816124636255 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Gb(0)[0x612000010ba0]{Idle}: Received Event E_MM_PDU_RECEPTION (gprs_gmm.c:2333)[0;m [1;33m20240816124636255 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000036/e7e27a3f) -> GMM IDENTITY RESPONSE: MI=IMEI-499990000000360 (gprs_gmm.c:1084)[0;m [1;33m20240816124636255 [1;33mDMM[0;m[1;33m [1;33mNOTICE[0;m[1;33m MM(262420000000036/e7e27a3f) Stopping *inactive* MM timer 3370 (gprs_gmm.c:115)[0;m [1;33m20240816124636255 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{CheckIdentity}: Received Event E_IDEN_RESP_RECV (gprs_gmm.c:1128)[0;m [1;33m20240816124636255 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{CheckIdentity}: state_chg to Authenticate (gprs_gmm_attach.c:115)[0;m [1;33m20240816124636255 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{Authenticate}: state_chg to AskVLR (gprs_gmm_attach.c:143)[0;m [1;33m20240816124636255 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000036/e7e27a3f) Requesting authorization (sgsn_auth.c:160)[0;m [1;33m20240816124636256 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000036/e7e27a3f) Requesting authentication tuples (sgsn_auth.c:184)[0;m [1;33m20240816124636256 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000036/e7e27a3f) Requesting subscriber authentication info (gprs_subscriber.c:921)[0;m 20240816124636256 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000036) requesting auth info (gprs_subscriber.c:805) 20240816124636256 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000036) Sending GSUP, will send: 08 01 08 62 42 02 00 00 00 30 f6 28 01 01 (gprs_subscriber.c:210) SGSN_Test-GSUP(362)@bb9044106d99: Found GsupExpect[0] for "262420000000036" handled at TC_attach_check_complete_resend(364) SGSN_Test-GSUP(362)@bb9044106d99: Added IMSI table entry 0TC_attach_check_complete_resend(364)"262420000000036" 20240816124636258 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000036) Received GSUP message OSMO_GSUP_MSGT_SEND_AUTH_INFO_RESULT (gprs_subscriber.c:723) 20240816124636258 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000036) Got SendAuthenticationInfoResult, num_auth_vectors = 1 (gprs_subscriber.c:242) 20240816124636258 [1;34mDGPRS[0;m [1;34mDEBUG[0;m SUBSCR(262420000000036) Adding auth tuple, cksn = 0 (gprs_subscriber.c:255) 20240816124636258 [1;34mDGPRS[0;m [1;34mDEBUG[0;m SUBSCR(262420000000036) Updating subscriber authentication info (gprs_subscriber.c:850) [1;33m20240816124636258 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000036/e7e27a3f) Subscriber data update (mmctx.c:430)[0;m [1;33m20240816124636258 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000036/e7e27a3f) Updating authorization (unknown -> authenticate) (sgsn_auth.c:217)[0;m [1;33m20240816124636259 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000036/e7e27a3f) Got authorization update: state unknown -> authenticate (sgsn_auth.c:246)[0;m [1;33m20240816124636259 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{AskVLR}: Received Event E_VLR_ANSWERED (gprs_gmm.c:991)[0;m [1;33m20240816124636259 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{AskVLR}: state_chg to Authenticate (gprs_gmm_attach.c:253)[0;m [1;33m20240816124636259 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000036/e7e27a3f) <- GMM AUTH AND CIPHERING REQ (rand = e8 e7 4f 96 0d 6b 14 06 dc c7 93 99 e1 57 84 73 , mmctx_is_r99=0, vec->auth_types=0x1[0;m[1;33m) (gprs_gmm.c:486)[0;m [38;5;57m20240816124636264 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x612000004ba0]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m 20240816124636264 [1;34mDLLC[0;m [1;34mDEBUG[0;m LLC SAPI=1 C U GEA0 IOV-UI=0x000000 FCS=0xe44d18 CMD=UI DATA (gprs_llc_parse.c:89) [1;33m20240816124636264 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Gb(0)[0x612000010ba0]{Idle}: Received Event E_MM_PDU_RECEPTION (gprs_gmm.c:2333)[0;m [1;33m20240816124636264 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000036/e7e27a3f) -> GMM AUTH AND CIPH RESPONSE (gprs_gmm.c:620)[0;m [1;33m20240816124636264 [1;33mDMM[0;m[1;33m [1;33mNOTICE[0;m[1;33m MM(262420000000036/e7e27a3f) Stopping *inactive* MM timer 3360 (gprs_gmm.c:115)[0;m [1;33m20240816124636264 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000036/e7e27a3f) checking auth: received GSM SRES = fd b3 64 bd (gprs_gmm.c:666)[0;m [1;33m20240816124636264 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{Authenticate}: Received Event E_AUTH_RESP_RECV_SUCCESS (gprs_gmm.c:681)[0;m [1;33m20240816124636264 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000036/e7e27a3f) Requesting authorization (sgsn_auth.c:160)[0;m [1;33m20240816124636264 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000036/e7e27a3f) Missing information, requesting subscriber data (sgsn_auth.c:195)[0;m [1;33m20240816124636264 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000036/e7e27a3f) Requesting subscriber data update (gprs_subscriber.c:894)[0;m 20240816124636264 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000036) subscriber data is not available (gprs_subscriber.c:818) 20240816124636264 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000036) Sending GSUP, will send: 04 01 08 62 42 02 00 00 00 30 f6 28 01 01 2a 01 01 (gprs_subscriber.c:210) [1;33m20240816124636265 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{Authenticate}: state_chg to WaitAttachComplete (gprs_gmm_attach.c:181)[0;m [1;33m20240816124636265 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000036/e7e27a3f) <- GMM ATTACH ACCEPT (new P-TMSI=0xe7e27a3f) (gprs_gmm.c:300)[0;m 20240816124636266 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000036) Received GSUP message OSMO_GSUP_MSGT_INSERT_DATA_REQUEST (gprs_subscriber.c:723) 20240816124636266 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000036) Will set PDP info, context id = 0, APN = 2a (gprs_subscriber.c:367) 20240816124636266 [1;34mDGPRS[0;m [1;34mDEBUG[0;m SUBSCR(262420000000036) Updating subscriber data (gprs_subscriber.c:839) [1;33m20240816124636266 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000036/e7e27a3f) Subscriber data update (mmctx.c:430)[0;m [1;33m20240816124636266 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000036/e7e27a3f) Updating authorization (authenticate -> accepted) (sgsn_auth.c:217)[0;m [1;33m20240816124636266 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000036/e7e27a3f) Got authorization update: state authenticate -> accepted (sgsn_auth.c:246)[0;m [1;33m20240816124636266 [1;33mDMM[0;m[1;33m [1;33mNOTICE[0;m[1;33m MM(262420000000036/e7e27a3f) Authorized, continuing procedure, IMSI=262420000000036 (gprs_gmm.c:1000)[0;m [1;33m20240816124636266 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{WaitAttachComplete}: Received Event E_VLR_ANSWERED (gprs_gmm.c:1005)[0;m [1;33m20240816124636266 [1;33mDMM[0;m[1;33m [1;33mNOTICE[0;m[1;33m MM(262420000000036/e7e27a3f) Unusual event: if MS got no data connection, check that it has APN configured. (gprs_gmm_attach.c:217)[0;m 20240816124636266 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000036) Sending GSUP, will send: 12 01 08 62 42 02 00 00 00 30 f6 28 01 01 (gprs_subscriber.c:210) 20240816124636266 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000036) Received GSUP message OSMO_GSUP_MSGT_UPDATE_LOCATION_RESULT (gprs_subscriber.c:723) 20240816124636266 [1;34mDGPRS[0;m [1;34mDEBUG[0;m SUBSCR(262420000000036) Updating subscriber data (gprs_subscriber.c:839) [1;33m20240816124636266 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000036/e7e27a3f) Subscriber data update (mmctx.c:430)[0;m [1;33m20240816124636266 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000036/e7e27a3f) Updating authorization (accepted -> accepted) (sgsn_auth.c:217)[0;m TC_attach_check_complete_resend(364)@bb9044106d99: Warning: Re-starting timer T, which is already active (running or expired). [1;33m20240816124642265 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{WaitAttachComplete}: Timeout of T3350 (fsm.c:317)[0;m [1;33m20240816124642265 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000036/e7e27a3f) <- GMM ATTACH ACCEPT (new P-TMSI=0xe7e27a3f) (gprs_gmm.c:300)[0;m TC_attach_check_complete_resend(364)@bb9044106d99: Warning: Re-starting timer T, which is already active (running or expired). 20240816124645596 [1;34mDGPRS[0;m [1;34mDEBUG[0;m Checking for inactive LLMEs, time = 5623139 (sgsn.c:131) [1;33m20240816124648266 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{WaitAttachComplete}: Timeout of T3350 (fsm.c:317)[0;m [1;33m20240816124648266 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000036/e7e27a3f) <- GMM ATTACH ACCEPT (new P-TMSI=0xe7e27a3f) (gprs_gmm.c:300)[0;m TC_attach_check_complete_resend(364)@bb9044106d99: Warning: Re-starting timer T, which is already active (running or expired). [1;33m20240816124654267 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{WaitAttachComplete}: Timeout of T3350 (fsm.c:317)[0;m [1;33m20240816124654267 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000036/e7e27a3f) <- GMM ATTACH ACCEPT (new P-TMSI=0xe7e27a3f) (gprs_gmm.c:300)[0;m TC_attach_check_complete_resend(364)@bb9044106d99: Warning: Re-starting timer T, which is already active (running or expired). [38;5;39m20240816124655196 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP ping callback (connected, got PONG) (gsup_client.c:266)[0;m [38;5;39m20240816124655196 [1;34mDLGSUP[0;m[38;5;39m [1;34mDEBUG[0;m[38;5;39m GSUP sending PING (gsup_client.c:288)[0;m SGSN_Test-GSUP-IPA(361)@bb9044106d99: CCM Rx:{ msg_type := IPAC_MSGT_PING (0), u := omit } SGSN_Test-GSUP-IPA(361)@bb9044106d99: CCM Tx:{ msg_type := IPAC_MSGT_PONG (1), u := omit } [38;5;39m20240816124655197 [1;34mDLGSUP[0;m[38;5;39m [1;34mDEBUG[0;m[38;5;39m GSUP receiving PONG (gsup_client.c:225)[0;m [1;33m20240816124700268 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{WaitAttachComplete}: Timeout of T3350 (fsm.c:317)[0;m [1;33m20240816124700268 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000036/e7e27a3f) <- GMM ATTACH ACCEPT (new P-TMSI=0xe7e27a3f) (gprs_gmm.c:300)[0;m TC_attach_check_complete_resend(364)@bb9044106d99: Warning: Re-starting timer T, which is already active (running or expired). [38;5;63m20240816124704371 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;63m20240816124704373 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20240816124704373 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x612000004ba0]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960)[0;m [38;5;63m20240816124704405 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;63m20240816124704406 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20240816124704406 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x612000004d20]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960)[0;m [38;5;63m20240816124704442 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;63m20240816124704443 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20240816124704443 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x612000004ea0]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960)[0;m [1;33m20240816124706269 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{WaitAttachComplete}: Timeout of T3350 (fsm.c:317)[0;m [1;33m20240816124706269 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{WaitAttachComplete}: Received Event E_REJECT (gprs_gmm_attach.c:444)[0;m [1;33m20240816124706269 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{WaitAttachComplete}: state_chg to Reject (gprs_gmm_attach.c:397)[0;m 20240816124706269 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000036) purging MS subscriber (gprs_subscriber.c:785) 20240816124706269 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000036) Sending GSUP, will send: 0c 01 08 62 42 02 00 00 00 30 f6 09 00 28 01 01 (gprs_subscriber.c:210) [1;33m20240816124706269 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x612000010a20]{Reject}: Deallocated (fsm.c:568)[0;m [1;33m20240816124706269 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Gb(0)[0x612000010ba0]{Idle}: Deallocated (fsm.c:568)[0;m [1;33m20240816124706270 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Iu[0x612000010d20]{Detached}: Deallocated (fsm.c:568)[0;m [1;33m20240816124706270 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM(gmm_fsm)[0x6120000108a0]{CommonProcedureInitiated}: Deallocated (fsm.c:568)[0;m 20240816124706270 [1;33mDLLC[0;m [1;33mNOTICE[0;m LLME(cff8bd92/e7e27a3f){ASSIGNED} LLGM Assign pre (e7e27a3f => ffffffff) (gprs_llc.c:1079) 20240816124706270 [1;33mDLLC[0;m [1;33mNOTICE[0;m LLME(00000000/00000000){UNASSIGNED} LLGM Assign post (e7e27a3f => ffffffff) (gprs_llc.c:1125) [0;94m[testenv][generic] Testsuite is done[0m [1;34m[testenv][generic] Stopping testsuite (180725)[0m [1;34m[testenv][generic] Merging log files[0m [0;94m[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-asan/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-asan/ws/_cache/git',> '-e', 'PATH=<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-asan/ws/_testenv/da…>:<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-asan/ws/_cache/podm…>:/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-asan/74/artifact/lo…',> 'testenv-sgsn-generic-osmocom-nightly-asan-20240816-1242-e766b8ba', 'sh', '-c', '<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-asan/ws/_cache/podm…> SGSN_Tests --rm >/dev/null'][0m Error: container bb9044106d99740e0b73386982751f86cd521fbd5e9223776ed9026150a64a39 does not exist in database: no such container [1;91m[testenv] podman container crashed![0m Error: no container with name or ID testenv-sgsn-generic-osmocom-nightly-asan-20240816-1242-e766b8ba found: no such container [1;91m[testenv][generic] Command failed unexpectedly[0m [0;94m[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-asan/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-asan/ws/_cache/git',> '-e', 'PATH=<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-asan/ws/_testenv/da…>:<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-asan/ws/_cache/podm…>:/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-asan/74/artifact/lo…',> 'testenv-sgsn-generic-osmocom-nightly-asan-20240816-1242-e766b8ba', 'sh', '-c', '<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-asan/ws/_cache/podm…> SGSN_Tests --rm >/dev/null'][0m [0;94m[testenv][generic] Returncode: 125[0m Traceback (most recent call last): File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-asan/ws/./testenv.py",> line 115, in <module> main() File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-asan/ws/./testenv.py",> line 104, in main run() File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-asan/ws/./testenv.py",> line 63, in run testenv.testsuite.run(cfg) File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-asan/ws/_testenv/te…",> line 199, in run merge_log_files(cfg) File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-asan/ws/_testenv/te…",> line 131, in merge_log_files testenv.cmd.run(cmd, cwd=cwd) File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-asan/ws/_testenv/te…",> 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-asan/ws/_testenv/te…",> line 133, in exec_cmd testenv.cmd.run( File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-asan/ws/_testenv/te…",> line 103, in run exit_error_cmd(p, "Command failed unexpectedly") File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-asan/ws/_testenv/te…",> 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 [1;34m[testenv][generic] Logs saved to: https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-asan/74/artifact/lo… [0m Build step 'Execute shell' marked build as failure Recording test results [Checks API] No suitable checks publisher found.

1 0

Build failed in Jenkins: ttcn3-sgsn-test-io_uring #165
by jenkins＠lists.osmocom.org 16 Aug '24

16 Aug '24

See <https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/165/displa…> 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/…> SGSN_Tests.TC_hlr_location_cancel_request_withdraw pass'. Fri Aug 16 12:03:19 UTC 2024 [1;32m====== SGSN_Tests.TC_hlr_location_cancel_request_withdraw pass ======[0m Waiting for packet dumper to finish... 0 (prev_count=-1, count=44100) [38;5;39m20240816120320350 [1;33mDLGSUP[0;m[38;5;39m [1;33mNOTICE[0;m[38;5;39m GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74)[0;m [38;5;39m20240816120320350 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151)[0;m Waiting for packet dumper to finish... 1 (prev_count=44100, count=93200) [38;5;39m20240816120321351 [1;33mDLGSUP[0;m[38;5;39m [1;33mNOTICE[0;m[38;5;39m GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74)[0;m [38;5;39m20240816120321352 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151)[0;m MTC@a6473498aab6: External command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/…> 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/…> 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/artifa…"> ><https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/165/artifa…> 2>/tmp/cmderr & Waiting for packet dumper to start... 0 [38;5;39m20240816120322353 [1;33mDLGSUP[0;m[38;5;39m [1;33mNOTICE[0;m[38;5;39m GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74)[0;m [38;5;39m20240816120322353 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151)[0;m MTC@a6473498aab6: External command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/…> 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 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m Accept()ed new telnet connection r=127.0.0.1:58490<->l=127.0.0.10:4245 (telnet_interface.c:192) [38;5;35m20240816120322476 [1;32mDLGTP[0;m[38;5;35m [1;32mINFO[0;m[38;5;35m Clearing req & resp retransmit queues (gsn.c:365)[0;m 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 [38;5;63m20240816120322515 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-RESET (gprs_ns2.c:1309)[0;m [38;5;57m20240816120322515 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;57m20240816120322515 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;57m20240816120322515 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00096) NS-STATUS.ind(bvci=00000): cause=NSE failure, transfer=0, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240816120322515 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 96 became unavailable (gprs_ns.c:54) [38;5;63m20240816120322515 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-RESET-ACK (gprs_ns2_message.c:331)[0;m [38;5;57m20240816120322515 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;63m20240816120322515 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;57m20240816120322515 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m -NSVCI97(407)@a6473498aab6: NSVC 97 State Transition: NSVC_S_WAIT_RESET (2) -> NSVC_S_ALIVE_BLOCKED (3) [38;5;63m20240816120322516 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-ALIVE (gprs_ns2.c:1309)[0;m [38;5;57m20240816120322516 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;63m20240816120322516 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-ALIVE-ACK (gprs_ns2_message.c:193)[0;m [38;5;63m20240816120322516 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-UNBLOCK (gprs_ns2.c:1309)[0;m [38;5;57m20240816120322516 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;63m20240816120322516 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-UNBLOCK-ACK (gprs_ns2_message.c:193)[0;m [38;5;57m20240816120322516 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;57m20240816120322516 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00096) NS-STATUS.ind(bvci=00000): cause=NSE recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240816120322516 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 96 became available (gprs_ns.c:43) [38;5;57m20240816120322516 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00096)-NSVC(00097) NS-STATUS.ind(bvci=00000): cause=NSVC recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:571)[0;m 20240816120322516 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS: indication Unknown prim 2 from NS (gprs_ns.c:57) [38;5;63m20240816120322516 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20240816120322516 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m -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) [38;5;57m20240816120322517 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m 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) [38;5;57m20240816120322521 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;59m20240816120322521 [1;33mDLBSSGP[0;m[38;5;59m [1;33mNOTICE[0;m[38;5;59m Cell 262-42-13135-0 CI 20960 on BVCI 196 (gprs_bssgp.c:400)[0;m 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 [38;5;63m20240816120322529 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-RESET (gprs_ns2.c:1309)[0;m [38;5;57m20240816120322529 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;57m20240816120322529 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;57m20240816120322529 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00097) NS-STATUS.ind(bvci=00000): cause=NSE failure, transfer=0, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240816120322529 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 97 became unavailable (gprs_ns.c:54) [38;5;63m20240816120322529 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-RESET-ACK (gprs_ns2_message.c:331)[0;m [38;5;57m20240816120322529 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;63m20240816120322529 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;57m20240816120322529 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;63m20240816120322530 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-ALIVE (gprs_ns2.c:1309)[0;m [38;5;57m20240816120322530 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m -NSVCI98(412)@a6473498aab6: NSVC 98 State Transition: NSVC_S_WAIT_RESET (2) -> NSVC_S_ALIVE_BLOCKED (3) [38;5;63m20240816120322530 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-ALIVE-ACK (gprs_ns2_message.c:193)[0;m [38;5;63m20240816120322530 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-UNBLOCK (gprs_ns2.c:1309)[0;m [38;5;57m20240816120322530 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;63m20240816120322530 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-UNBLOCK-ACK (gprs_ns2_message.c:193)[0;m [38;5;57m20240816120322530 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;57m20240816120322530 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00097) NS-STATUS.ind(bvci=00000): cause=NSE recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240816120322530 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 97 became available (gprs_ns.c:43) [38;5;57m20240816120322530 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00097)-NSVC(00098) NS-STATUS.ind(bvci=00000): cause=NSVC recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:571)[0;m 20240816120322530 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS: indication Unknown prim 2 from NS (gprs_ns.c:57) [38;5;63m20240816120322530 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20240816120322530 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m -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) [38;5;57m20240816120322532 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m 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) [38;5;57m20240816120322535 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;59m20240816120322536 [1;33mDLBSSGP[0;m[38;5;59m [1;33mNOTICE[0;m[38;5;59m Cell 262-42-13200-0 CI 20961 on BVCI 210 (gprs_bssgp.c:400)[0;m 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 [38;5;63m20240816120322543 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-RESET (gprs_ns2.c:1309)[0;m [38;5;57m20240816120322543 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;57m20240816120322543 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;57m20240816120322544 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00098) NS-STATUS.ind(bvci=00000): cause=NSE failure, transfer=0, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240816120322544 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 98 became unavailable (gprs_ns.c:54) [38;5;63m20240816120322544 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-RESET-ACK (gprs_ns2_message.c:331)[0;m [38;5;57m20240816120322544 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;63m20240816120322544 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;57m20240816120322544 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m -NSVCI99(417)@a6473498aab6: NSVC 99 State Transition: NSVC_S_WAIT_RESET (2) -> NSVC_S_ALIVE_BLOCKED (3) [38;5;63m20240816120322544 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-ALIVE (gprs_ns2.c:1309)[0;m [38;5;57m20240816120322544 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;63m20240816120322544 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-ALIVE-ACK (gprs_ns2_message.c:193)[0;m [38;5;63m20240816120322544 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-UNBLOCK (gprs_ns2.c:1309)[0;m [38;5;57m20240816120322544 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;63m20240816120322544 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-UNBLOCK-ACK (gprs_ns2_message.c:193)[0;m [38;5;57m20240816120322544 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;57m20240816120322544 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00098) NS-STATUS.ind(bvci=00000): cause=NSE recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240816120322544 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 98 became available (gprs_ns.c:43) [38;5;57m20240816120322544 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00098)-NSVC(00099) NS-STATUS.ind(bvci=00000): cause=NSVC recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:571)[0;m 20240816120322544 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS: indication Unknown prim 2 from NS (gprs_ns.c:57) [38;5;63m20240816120322544 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20240816120322544 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m -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) [38;5;57m20240816120322546 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m 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) [38;5;57m20240816120322549 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m 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)[0;m [38;5;59m20240816120322549 [1;33mDLBSSGP[0;m[38;5;59m [1;33mNOTICE[0;m[38;5;59m Cell 262-42-13200-0 CI 20962 on BVCI 220 (gprs_bssgp.c:400)[0;m TC_hlr_location_cancel_request_unknown_subscriber_withdraw-BVCI220(416)@a6473498aab6: BVCI(220) State Transition: BVC_S_BLOCKED (2) -> BVC_S_UNBLOCKED (3) [38;5;39m20240816120323354 [1;33mDLGSUP[0;m[38;5;39m [1;33mNOTICE[0;m[38;5;39m GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74)[0;m [38;5;23m20240816120323354 [1;33mDLINP[0;m[38;5;23m [1;33mNOTICE[0;m[38;5;23m 127.0.0.103:4222 connection done (ipa.c:143)[0;m [38;5;39m20240816120323354 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 UP (gsup_client.c:151)[0;m [38;5;39m20240816120323354 [1;34mDLGSUP[0;m[38;5;39m [1;34mDEBUG[0;m[38;5;39m GSUP sending PING (gsup_client.c:288)[0;m 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) } } } } [38;5;23m20240816120323358 [1;33mDLINP[0;m[38;5;23m [1;33mNOTICE[0;m[38;5;23m received ID_GET for unit ID 0/0/0 (ipaccess.c:897)[0;m 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 } } [38;5;39m20240816120323359 [1;34mDLGSUP[0;m[38;5;39m [1;34mDEBUG[0;m[38;5;39m GSUP receiving PONG (gsup_client.c:225)[0;m 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 [1;32mDGPRS[0;m [1;32mINFO[0;m 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 [1;33mDGPRS[0;m [1;33mNOTICE[0;m 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 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m 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 [38;5;23m20240816120324398 [1;31mDLINP[0;m[38;5;23m [1;31mERROR[0;m[38;5;23m 127.0.0.103:4222 connection closed with server (ipa.c:68)[0;m [38;5;39m20240816120324398 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151)[0;m 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/…> SGSN_Tests.TC_hlr_location_cancel_request_unknown_subscriber_withdraw pass'. Fri Aug 16 12:03:24 UTC 2024 [1;32m====== SGSN_Tests.TC_hlr_location_cancel_request_unknown_subscriber_withdraw pass ======[0m Waiting for packet dumper to finish... 0 (prev_count=-1, count=44516) Error: OCI runtime error: crun: the container `a6473498aab6080cd310c2e7facb778be7ff0a6ff937d362d2a2b2e7e29100c7` is not running [1;91m[testenv] podman container crashed![0m [0;94m[testenv][generic] Testsuite is done[0m [1;34m[testenv][generic] Stopping testsuite (2699682)[0m [1;34m[testenv][generic] Merging log files[0m [0;94m[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/…',> '-e', 'PATH=<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_testen…>:<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/…>:/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/artifa…',> 'testenv-sgsn-generic-osmocom-nightly-20240816-1158-a86509fe', 'sh', '-c', '<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/…> SGSN_Tests --rm >/dev/null'][0m Error: no container with name or ID "testenv-sgsn-generic-osmocom-nightly-20240816-1158-a86509fe" found: no such container [1;91m[testenv][generic] Command failed unexpectedly[0m [0;94m[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/…',> '-e', 'PATH=<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_testen…>:<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/…>:/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/artifa…',> 'testenv-sgsn-generic-osmocom-nightly-20240816-1158-a86509fe', 'sh', '-c', '<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_cache/…> SGSN_Tests --rm >/dev/null'][0m [0;94m[testenv][generic] Returncode: 125[0m Traceback (most recent call last): File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/./teste…",> line 115, in <module> main() File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/./teste…",> line 104, in main run() File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/./teste…",> line 63, in run testenv.testsuite.run(cfg) File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_testen…",> line 199, in run merge_log_files(cfg) File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_testen…",> 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/_testen…",> 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/_testen…",> line 133, in exec_cmd testenv.cmd.run( File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_testen…",> line 103, in run exit_error_cmd(p, "Command failed unexpectedly") File "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/ws/_testen…",> 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 [1;34m[testenv][generic] Logs saved to: https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-io_uring/165/artifa… [0m Build step 'Execute shell' marked build as failure Recording test results [Checks API] No suitable checks publisher found.

1 0

Build failed in Jenkins: ttcn3-sgsn-test #2441
by jenkins＠lists.osmocom.org 16 Aug '24

16 Aug '24

See <https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test/2441/display/redire…> Changes: ------------------------------------------ [...truncated 735.52 KB...] MTC@fabb34539fda: Starting external command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test/ws/_cache/podman/os…> SGSN_Tests.TC_attach_auth_sai_timeout pass'. Fri Aug 16 05:50:15 UTC 2024 [1;32m====== SGSN_Tests.TC_attach_auth_sai_timeout pass ======[0m Waiting for packet dumper to finish... 0 (prev_count=-1, count=57296) [38;5;39m20240816055016429 [1;33mDLGSUP[0;m[38;5;39m [1;33mNOTICE[0;m[38;5;39m GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74)[0;m [38;5;39m20240816055016429 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151)[0;m Waiting for packet dumper to finish... 1 (prev_count=57296, count=62684) [38;5;39m20240816055017430 [1;33mDLGSUP[0;m[38;5;39m [1;33mNOTICE[0;m[38;5;39m GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74)[0;m [38;5;39m20240816055017430 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151)[0;m MTC@fabb34539fda: External command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test/ws/_cache/podman/os…> SGSN_Tests.TC_attach_auth_sai_timeout pass' was executed successfully (exit status: 0). MTC@fabb34539fda: Starting external command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test/ws/_cache/podman/os…> SGSN_Tests.TC_attach_auth_sai_reject'. ------ SGSN_Tests.TC_attach_auth_sai_reject ------ Fri Aug 16 05:50:17 UTC 2024 /usr/bin/dumpcap -q -s 1520 -n -i any -w "<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test/2441/artifact/logs/…"> ><https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test/2441/artifact/logs/…> 2>/tmp/cmderr & Waiting for packet dumper to start... 0 [38;5;39m20240816055018431 [1;33mDLGSUP[0;m[38;5;39m [1;33mNOTICE[0;m[38;5;39m GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74)[0;m [38;5;39m20240816055018431 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151)[0;m MTC@fabb34539fda: External command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test/ws/_cache/podman/os…> SGSN_Tests.TC_attach_auth_sai_reject' was executed successfully (exit status: 0). MTC@fabb34539fda: Test case TC_attach_auth_sai_reject started. 20240816055018526 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m Accept()ed new telnet connection r=127.0.0.1:38218<->l=127.0.0.10:4245 (telnet_interface.c:192) [38;5;35m20240816055018528 [1;32mDLGTP[0;m[38;5;35m [1;32mINFO[0;m[38;5;35m Clearing req & resp retransmit queues (gsn.c:365)[0;m SGSN_Test-Gb0-NS0(136)@fabb34539fda: Creating NSIP provider for "127.0.0.103":21010 SGSN_Test-Gb0-BSSGP0(137)@fabb34539fda: BVCI(0) State Transition: BVC_S_WAIT_RESET (0) -> BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) SGSN_Test-Gb0-NS0(136)@fabb34539fda: 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(140)@fabb34539fda: NSVC 97 State Transition: NSVC_S_DEAD_BLOCKED (1) -> NSVC_S_DEAD_BLOCKED (1) -NSVCI97(140)@fabb34539fda: Provider Link came up: sending NS-RESET [38;5;63m20240816055018559 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-RESET (gprs_ns2.c:1309)[0;m [38;5;57m20240816055018559 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x55cd1cb9dc10]{UNBLOCKED}: Received Event RX-RESET (gprs_ns2_vc_fsm.c:934)[0;m [38;5;57m20240816055018559 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x55cd1cb9dc10]{UNBLOCKED}: state_chg to RESET (gprs_ns2_vc_fsm.c:657)[0;m [38;5;57m20240816055018559 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00096) NS-STATUS.ind(bvci=00000): cause=NSE failure, transfer=0, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240816055018559 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 96 became unavailable (gprs_ns.c:54) [38;5;63m20240816055018559 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-RESET-ACK (gprs_ns2_message.c:331)[0;m [38;5;57m20240816055018559 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x55cd1cb9dc10]{RESET}: state_chg to BLOCKED (gprs_ns2_vc_fsm.c:329)[0;m [38;5;63m20240816055018559 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;57m20240816055018559 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x55cd1cb9dc10]{BLOCKED}: Starting Tns-alive of 3 seconds (gprs_ns2_vc_fsm.c:177)[0;m [38;5;63m20240816055018559 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-ALIVE (gprs_ns2.c:1309)[0;m [38;5;57m20240816055018559 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x55cd1cb9dc10]{BLOCKED}: Received Event RX-ALIVE (gprs_ns2_vc_fsm.c:957)[0;m [38;5;63m20240816055018559 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-ALIVE-ACK (gprs_ns2_message.c:193)[0;m [38;5;63m20240816055018559 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-UNBLOCK (gprs_ns2.c:1309)[0;m [38;5;57m20240816055018559 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x55cd1cb9dc10]{BLOCKED}: Received Event RX-UNBLOCK (gprs_ns2_vc_fsm.c:951)[0;m [38;5;63m20240816055018559 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Tx NS-UNBLOCK-ACK (gprs_ns2_message.c:193)[0;m [38;5;57m20240816055018559 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x55cd1cb9dc10]{BLOCKED}: state_chg to UNBLOCKED (gprs_ns2_vc_fsm.c:414)[0;m [38;5;57m20240816055018559 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00096) NS-STATUS.ind(bvci=00000): cause=NSE recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240816055018559 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 96 became available (gprs_ns.c:43) [38;5;57m20240816055018559 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00096)-NSVC(00097) NS-STATUS.ind(bvci=00000): cause=NSVC recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:571)[0;m 20240816055018559 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS: indication Unknown prim 2 from NS (gprs_ns.c:57) -NSVCI97(140)@fabb34539fda: NSVC 97 State Transition: NSVC_S_WAIT_RESET (2) -> NSVC_S_ALIVE_BLOCKED (3) [38;5;63m20240816055018560 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00096)-NSVC(00097) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20240816055018560 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x55cd1cb9dc10]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960)[0;m -NSVCI97(140)@fabb34539fda: Rx NS-ALIVE-ACK: stopping Tns-alive; starting Tns-test -NSVCI97(140)@fabb34539fda: NSVC 97 State Transition: NSVC_S_ALIVE_BLOCKED (3) -> NSVC_S_ALIVE_UNBLOCKED (4) [38;5;57m20240816055018561 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x55cd1cb9dc10]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m SGSN_Test-Gb1-NS1(141)@fabb34539fda: Creating NSIP provider for "127.0.0.103":21011 SGSN_Test-Gb0-BSSGP0(137)@fabb34539fda: BVCI(0) Rx BVC-RESET-ACK SGSN_Test-Gb0-BSSGP0(137)@fabb34539fda: BVCI(0) State Transition: BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) -> BVC_S_UNBLOCKED (3) [38;5;57m20240816055018565 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x55cd1cb9dc10]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m [38;5;59m20240816055018565 [1;33mDLBSSGP[0;m[38;5;59m [1;33mNOTICE[0;m[38;5;59m Cell 262-42-13135-0 CI 20960 on BVCI 196 (gprs_bssgp.c:400)[0;m TC_attach_auth_sai_reject-BVCI196(139)@fabb34539fda: BVCI(196) State Transition: BVC_S_BLOCKED (2) -> BVC_S_UNBLOCKED (3) SGSN_Test-Gb1-BSSGP1(142)@fabb34539fda: BVCI(0) State Transition: BVC_S_WAIT_RESET (0) -> BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) SGSN_Test-Gb1-NS1(141)@fabb34539fda: 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(145)@fabb34539fda: NSVC 98 State Transition: NSVC_S_DEAD_BLOCKED (1) -> NSVC_S_DEAD_BLOCKED (1) -NSVCI98(145)@fabb34539fda: Provider Link came up: sending NS-RESET [38;5;63m20240816055018573 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-RESET (gprs_ns2.c:1309)[0;m [38;5;57m20240816055018573 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x55cd1cba1980]{UNBLOCKED}: Received Event RX-RESET (gprs_ns2_vc_fsm.c:934)[0;m [38;5;57m20240816055018573 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x55cd1cba1980]{UNBLOCKED}: state_chg to RESET (gprs_ns2_vc_fsm.c:657)[0;m [38;5;57m20240816055018573 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00097) NS-STATUS.ind(bvci=00000): cause=NSE failure, transfer=0, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240816055018573 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 97 became unavailable (gprs_ns.c:54) [38;5;63m20240816055018573 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-RESET-ACK (gprs_ns2_message.c:331)[0;m [38;5;57m20240816055018573 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x55cd1cba1980]{RESET}: state_chg to BLOCKED (gprs_ns2_vc_fsm.c:329)[0;m [38;5;63m20240816055018573 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;57m20240816055018573 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x55cd1cba1980]{BLOCKED}: Starting Tns-alive of 3 seconds (gprs_ns2_vc_fsm.c:177)[0;m -NSVCI98(145)@fabb34539fda: NSVC 98 State Transition: NSVC_S_WAIT_RESET (2) -> NSVC_S_ALIVE_BLOCKED (3) [38;5;63m20240816055018573 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-ALIVE (gprs_ns2.c:1309)[0;m [38;5;57m20240816055018573 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x55cd1cba1980]{BLOCKED}: Received Event RX-ALIVE (gprs_ns2_vc_fsm.c:957)[0;m [38;5;63m20240816055018573 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-ALIVE-ACK (gprs_ns2_message.c:193)[0;m [38;5;63m20240816055018573 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-UNBLOCK (gprs_ns2.c:1309)[0;m [38;5;57m20240816055018573 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x55cd1cba1980]{BLOCKED}: Received Event RX-UNBLOCK (gprs_ns2_vc_fsm.c:951)[0;m [38;5;63m20240816055018573 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Tx NS-UNBLOCK-ACK (gprs_ns2_message.c:193)[0;m [38;5;57m20240816055018573 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x55cd1cba1980]{BLOCKED}: state_chg to UNBLOCKED (gprs_ns2_vc_fsm.c:414)[0;m [38;5;57m20240816055018573 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00097) NS-STATUS.ind(bvci=00000): cause=NSE recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240816055018573 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 97 became available (gprs_ns.c:43) [38;5;57m20240816055018573 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00097)-NSVC(00098) NS-STATUS.ind(bvci=00000): cause=NSVC recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:571)[0;m 20240816055018573 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS: indication Unknown prim 2 from NS (gprs_ns.c:57) [38;5;63m20240816055018573 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00097)-NSVC(00098) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20240816055018573 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x55cd1cba1980]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960)[0;m -NSVCI98(145)@fabb34539fda: Rx NS-ALIVE-ACK: stopping Tns-alive; starting Tns-test -NSVCI98(145)@fabb34539fda: NSVC 98 State Transition: NSVC_S_ALIVE_BLOCKED (3) -> NSVC_S_ALIVE_UNBLOCKED (4) [38;5;57m20240816055018575 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x55cd1cba1980]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m SGSN_Test-Gb2-NS2(146)@fabb34539fda: Creating NSIP provider for "127.0.0.103":21012 SGSN_Test-Gb1-BSSGP1(142)@fabb34539fda: BVCI(0) Rx BVC-RESET-ACK SGSN_Test-Gb1-BSSGP1(142)@fabb34539fda: BVCI(0) State Transition: BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) -> BVC_S_UNBLOCKED (3) [38;5;57m20240816055018579 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00097-NSVC00098-127_0_0_10:23000-127_0_0_103:21011)[0x55cd1cba1980]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m [38;5;59m20240816055018579 [1;33mDLBSSGP[0;m[38;5;59m [1;33mNOTICE[0;m[38;5;59m Cell 262-42-13200-0 CI 20961 on BVCI 210 (gprs_bssgp.c:400)[0;m TC_attach_auth_sai_reject-BVCI210(144)@fabb34539fda: BVCI(210) State Transition: BVC_S_BLOCKED (2) -> BVC_S_UNBLOCKED (3) SGSN_Test-Gb2-BSSGP2(147)@fabb34539fda: BVCI(0) State Transition: BVC_S_WAIT_RESET (0) -> BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) SGSN_Test-Gb2-NS2(146)@fabb34539fda: 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(150)@fabb34539fda: NSVC 99 State Transition: NSVC_S_DEAD_BLOCKED (1) -> NSVC_S_DEAD_BLOCKED (1) -NSVCI99(150)@fabb34539fda: Provider Link came up: sending NS-RESET [38;5;63m20240816055018587 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-RESET (gprs_ns2.c:1309)[0;m [38;5;57m20240816055018587 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x55cd1cba3240]{UNBLOCKED}: Received Event RX-RESET (gprs_ns2_vc_fsm.c:934)[0;m [38;5;57m20240816055018587 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x55cd1cba3240]{UNBLOCKED}: state_chg to RESET (gprs_ns2_vc_fsm.c:657)[0;m [38;5;57m20240816055018587 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00098) NS-STATUS.ind(bvci=00000): cause=NSE failure, transfer=0, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240816055018587 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 98 became unavailable (gprs_ns.c:54) [38;5;63m20240816055018587 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-RESET-ACK (gprs_ns2_message.c:331)[0;m [38;5;57m20240816055018587 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x55cd1cba3240]{RESET}: state_chg to BLOCKED (gprs_ns2_vc_fsm.c:329)[0;m [38;5;63m20240816055018587 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-ALIVE (gprs_ns2_message.c:193)[0;m [38;5;57m20240816055018587 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x55cd1cba3240]{BLOCKED}: Starting Tns-alive of 3 seconds (gprs_ns2_vc_fsm.c:177)[0;m -NSVCI99(150)@fabb34539fda: NSVC 99 State Transition: NSVC_S_WAIT_RESET (2) -> NSVC_S_ALIVE_BLOCKED (3) [38;5;63m20240816055018587 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-ALIVE (gprs_ns2.c:1309)[0;m [38;5;57m20240816055018587 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x55cd1cba3240]{BLOCKED}: Received Event RX-ALIVE (gprs_ns2_vc_fsm.c:957)[0;m [38;5;63m20240816055018587 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-ALIVE-ACK (gprs_ns2_message.c:193)[0;m [38;5;63m20240816055018587 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-UNBLOCK (gprs_ns2.c:1309)[0;m [38;5;57m20240816055018587 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x55cd1cba3240]{BLOCKED}: Received Event RX-UNBLOCK (gprs_ns2_vc_fsm.c:951)[0;m [38;5;63m20240816055018587 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Tx NS-UNBLOCK-ACK (gprs_ns2_message.c:193)[0;m [38;5;57m20240816055018587 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x55cd1cba3240]{BLOCKED}: state_chg to UNBLOCKED (gprs_ns2_vc_fsm.c:414)[0;m [38;5;57m20240816055018587 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00098) NS-STATUS.ind(bvci=00000): cause=NSE recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:575)[0;m 20240816055018587 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS-E 98 became available (gprs_ns.c:43) [38;5;57m20240816055018587 [1;33mDLNS[0;m[38;5;57m [1;33mNOTICE[0;m[38;5;57m NSE(00098)-NSVC(00099) NS-STATUS.ind(bvci=00000): cause=NSVC recovery, transfer=100, first=0, mtu=65523 (gprs_ns2.c:571)[0;m 20240816055018587 [1;33mDGPRS[0;m [1;33mNOTICE[0;m NS: indication Unknown prim 2 from NS (gprs_ns.c:57) [38;5;63m20240816055018587 [1;32mDLNSSIGNAL[0;m[38;5;63m [1;32mINFO[0;m[38;5;63m NSE(00098)-NSVC(00099) Rx NS-ALIVE-ACK (gprs_ns2.c:1309)[0;m [38;5;57m20240816055018587 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x55cd1cba3240]{UNBLOCKED}: Received Event RX-ALIVE_ACK (gprs_ns2_vc_fsm.c:960)[0;m -NSVCI99(150)@fabb34539fda: Rx NS-ALIVE-ACK: stopping Tns-alive; starting Tns-test -NSVCI99(150)@fabb34539fda: NSVC 99 State Transition: NSVC_S_ALIVE_BLOCKED (3) -> NSVC_S_ALIVE_UNBLOCKED (4) [38;5;57m20240816055018589 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x55cd1cba3240]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m SGSN_Test-Gb2-BSSGP2(147)@fabb34539fda: BVCI(0) Rx BVC-RESET-ACK SGSN_Test-Gb2-BSSGP2(147)@fabb34539fda: BVCI(0) State Transition: BVC_S_WAIT_NS_ALIVE_UNBLOCKED (1) -> BVC_S_UNBLOCKED (3) [38;5;57m20240816055018593 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00098-NSVC00099-127_0_0_10:23000-127_0_0_103:21012)[0x55cd1cba3240]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m [38;5;59m20240816055018593 [1;33mDLBSSGP[0;m[38;5;59m [1;33mNOTICE[0;m[38;5;59m Cell 262-42-13200-0 CI 20962 on BVCI 220 (gprs_bssgp.c:400)[0;m TC_attach_auth_sai_reject-BVCI220(149)@fabb34539fda: BVCI(220) State Transition: BVC_S_BLOCKED (2) -> BVC_S_UNBLOCKED (3) [38;5;39m20240816055019432 [1;33mDLGSUP[0;m[38;5;39m [1;33mNOTICE[0;m[38;5;39m GSUP connecting to 127.0.0.103:4222 (gsup_client.c:74)[0;m [38;5;23m20240816055019432 [1;33mDLINP[0;m[38;5;23m [1;33mNOTICE[0;m[38;5;23m 127.0.0.103:4222 connection done (ipa.c:143)[0;m [38;5;39m20240816055019432 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 UP (gsup_client.c:151)[0;m [38;5;39m20240816055019432 [1;34mDLGSUP[0;m[38;5;39m [1;34mDEBUG[0;m[38;5;39m GSUP sending PING (gsup_client.c:288)[0;m SGSN_Test-GSUP-IPA(151)@fabb34539fda: Established a new IPA connection (conn_id=2) SGSN_Test-GSUP-IPA(151)@fabb34539fda: 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) } } } } [38;5;23m20240816055019436 [1;33mDLINP[0;m[38;5;23m [1;33mNOTICE[0;m[38;5;23m received ID_GET for unit ID 0/0/0 (ipaccess.c:897)[0;m [38;5;39m20240816055019437 [1;34mDLGSUP[0;m[38;5;39m [1;34mDEBUG[0;m[38;5;39m GSUP receiving PONG (gsup_client.c:225)[0;m SGSN_Test-GSUP-IPA(151)@fabb34539fda: CCM Rx:{ msg_type := IPAC_MSGT_PING (0), u := omit } SGSN_Test-GSUP-IPA(151)@fabb34539fda: CCM Tx:{ msg_type := IPAC_MSGT_PONG (1), u := omit } SGSN_Test-GSUP-IPA(151)@fabb34539fda: 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(151)@fabb34539fda: IPA ID 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(151)@fabb34539fda: CCM Tx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } SGSN_Test-GSUP-IPA(151)@fabb34539fda: CCM Rx:{ msg_type := IPAC_MSGT_ID_ACK (6), u := omit } TC_attach_auth_sai_reject-BVCI196(139)@fabb34539fda: Adding Client=TC_attach_auth_sai_reject(154), IMSI='262420000000004'H, TLLI='F5A900AA'O, index=0 SGSN_Test-GSUP(152)@fabb34539fda: Created GsupExpect[0] for "262420000000004" to be handled at TC_attach_auth_sai_reject(154) [38;5;57m20240816055019472 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x55cd1cb9dc10]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m 20240816055019472 [1;33mDLLC[0;m [1;33mNOTICE[0;m LLME(ffffffff/f5a900aa){UNASSIGNED} LLC RX: unknown TLLI 0xf5a900aa, creating LLME on the fly (gprs_llc.c:552) 20240816055019472 [1;34mDLLC[0;m [1;34mDEBUG[0;m LLC SAPI=1 C U GEA0 IOV-UI=0x000000 FCS=0x24bf94 CMD=UI DATA (gprs_llc_parse.c:89) [1;33m20240816055019472 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(---/ffffffff) -> GMM ATTACH REQUEST [0;m[1;33mMI(IMSI-262420000000004) type="GPRS attach" [0;m[1;33m (gprs_gmm.c:1266)[0;m [1;33m20240816055019472 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM(gmm_fsm)[0x55cd1cb9ed90]{Deregistered}: Allocated (fsm.c:456)[0;m [1;33m20240816055019472 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x55cd1cba63a0]{Init}: Allocated (fsm.c:456)[0;m [1;33m20240816055019472 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Gb[0x55cd1cb9eff0]{Idle}: Allocated (fsm.c:456)[0;m [1;33m20240816055019472 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Iu[0x55cd1cb9eec0]{Detached}: Allocated (fsm.c:456)[0;m [1;33m20240816055019472 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM(gmm_fsm)[0x55cd1cb9ed90]{Deregistered}: Received Event E_GMM_COMMON_PROC_INIT_REQ (gprs_gmm.c:1144)[0;m [1;33m20240816055019472 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM(gmm_fsm)[0x55cd1cb9ed90]{Deregistered}: state_chg to CommonProcedureInitiated (gprs_gmm_fsm.c:49)[0;m 20240816055019472 [1;33mDLLC[0;m [1;33mNOTICE[0;m LLME(ffffffff/f5a900aa){UNASSIGNED} LLGM Assign pre (f5a900aa => cbfadb3d) (gprs_llc.c:1079) 20240816055019472 [1;33mDLLC[0;m [1;33mNOTICE[0;m LLME(f5a900aa/cbfadb3d){ASSIGNED} LLGM Assign post (f5a900aa => cbfadb3d) (gprs_llc.c:1125) [1;33m20240816055019472 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x55cd1cba63a0]{Init}: Received Event E_ATTACH_REQ_RECV (gprs_gmm.c:1370)[0;m [1;33m20240816055019472 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x55cd1cba63a0]{Init}: state_chg to CheckIdentity (gprs_gmm_attach.c:52)[0;m [1;33m20240816055019472 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000004/cbfadb3d) <- GMM IDENTITY REQUEST: mi_type=IMEI (gprs_gmm.c:431)[0;m [38;5;57m20240816055019490 [1;34mDLNS[0;m[38;5;57m [1;34mDEBUG[0;m[38;5;57m GPRS-NS2-VC(UDP-NSE00096-NSVC00097-127_0_0_10:23000-127_0_0_103:21010)[0x55cd1cb9dc10]{UNBLOCKED}: Received Event RX-UNITDATA (gprs_ns2_vc_fsm.c:964)[0;m 20240816055019490 [1;34mDLLC[0;m [1;34mDEBUG[0;m LLC SAPI=1 C U GEA0 IOV-UI=0x000000 FCS=0x612fca CMD=UI DATA (gprs_llc_parse.c:89) [1;33m20240816055019490 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Gb(0)[0x55cd1cb9eff0]{Idle}: Received Event E_MM_PDU_RECEPTION (gprs_gmm.c:2333)[0;m [1;33m20240816055019490 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000004/cbfadb3d) -> GMM IDENTITY RESPONSE: MI=IMEI-499990000000040 (gprs_gmm.c:1084)[0;m [1;33m20240816055019490 [1;33mDMM[0;m[1;33m [1;33mNOTICE[0;m[1;33m MM(262420000000004/cbfadb3d) Stopping *inactive* MM timer 3370 (gprs_gmm.c:115)[0;m [1;33m20240816055019490 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x55cd1cba63a0]{CheckIdentity}: Received Event E_IDEN_RESP_RECV (gprs_gmm.c:1128)[0;m [1;33m20240816055019490 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x55cd1cba63a0]{CheckIdentity}: state_chg to Authenticate (gprs_gmm_attach.c:115)[0;m [1;33m20240816055019490 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x55cd1cba63a0]{Authenticate}: state_chg to AskVLR (gprs_gmm_attach.c:143)[0;m [1;33m20240816055019490 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000004/cbfadb3d) Requesting authorization (sgsn_auth.c:160)[0;m [1;33m20240816055019490 [1;32mDMM[0;m[1;33m [1;32mINFO[0;m[1;33m MM(262420000000004/cbfadb3d) Requesting authentication tuples (sgsn_auth.c:184)[0;m [1;33m20240816055019490 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM(262420000000004/cbfadb3d) Requesting subscriber authentication info (gprs_subscriber.c:921)[0;m 20240816055019490 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000004) requesting auth info (gprs_subscriber.c:805) 20240816055019490 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000004) Sending GSUP, will send: 08 01 08 62 42 02 00 00 00 00 f4 28 01 01 (gprs_subscriber.c:210) SGSN_Test-GSUP(152)@fabb34539fda: Found GsupExpect[0] for "262420000000004" handled at TC_attach_auth_sai_reject(154) SGSN_Test-GSUP(152)@fabb34539fda: Added IMSI table entry 0TC_attach_auth_sai_reject(154)"262420000000004" 20240816055019497 [1;32mDGPRS[0;m [1;32mINFO[0;m SUBSCR(262420000000004) Received GSUP message OSMO_GSUP_MSGT_SEND_AUTH_INFO_ERROR (gprs_subscriber.c:723) 20240816055019497 [1;34mDGPRS[0;m [1;34mDEBUG[0;m SUBSCR(262420000000004) Send authentication info has failed with cause 23, handled as: Invalid argument (gprs_subscriber.c:477) 20240816055019497 [1;31mDGPRS[0;m [1;31mERROR[0;m SUBSCR(262420000000004) GSUP protocol remote error, GMM cause = 'GSM authentication unacceptable' (23) (gprs_subscriber.c:511) [1;33m20240816055025491 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x55cd1cba63a0]{AskVLR}: Timeout of T3350 (fsm.c:317)[0;m [1;33m20240816055025491 [1;31mDMM[0;m[1;33m [1;31mERROR[0;m[1;33m MM(262420000000004/cbfadb3d) HLR did not answer in time. Rejecting. (gprs_gmm_attach.c:415)[0;m [1;33m20240816055025491 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x55cd1cba63a0]{AskVLR}: Received Event E_REJECT (gprs_gmm_attach.c:416)[0;m [1;33m20240816055025491 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x55cd1cba63a0]{AskVLR}: state_chg to Reject (gprs_gmm_attach.c:397)[0;m [1;33m20240816055025491 [1;33mDMM[0;m[1;33m [1;33mNOTICE[0;m[1;33m MM(262420000000004/cbfadb3d) <- GMM ATTACH REJECT: Network failure (gprs_gmm.c:364)[0;m [1;33m20240816055025491 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM_ATTACH_REQ_FSM(gb_gmm_req)[0x55cd1cba63a0]{Reject}: Deallocated (fsm.c:568)[0;m [1;33m20240816055025491 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Gb(0)[0x55cd1cb9eff0]{Idle}: Deallocated (fsm.c:568)[0;m [1;33m20240816055025491 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m MM_STATE_Iu[0x55cd1cb9eec0]{Detached}: Deallocated (fsm.c:568)[0;m [1;33m20240816055025491 [1;34mDMM[0;m[1;33m [1;34mDEBUG[0;m[1;33m GMM(gmm_fsm)[0x55cd1cb9ed90]{CommonProcedureInitiated}: Deallocated (fsm.c:568)[0;m 20240816055025491 [1;33mDLLC[0;m [1;33mNOTICE[0;m LLME(f5a900aa/cbfadb3d){ASSIGNED} LLGM Assign pre (cbfadb3d => ffffffff) (gprs_llc.c:1079) 20240816055025491 [1;33mDLLC[0;m [1;33mNOTICE[0;m LLME(00000000/00000000){UNASSIGNED} LLGM Assign post (cbfadb3d => ffffffff) (gprs_llc.c:1125) TC_attach_auth_sai_reject(154)@fabb34539fda: setverdict(pass): none -> pass TC_attach_auth_sai_reject-BVCI196(139)@fabb34539fda: Removing Client IMSI='262420000000004'H, index=0 TC_attach_auth_sai_reject(154)@fabb34539fda: Final verdict of PTC: pass 20240816055025503 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m Closing telnet connection r=127.0.0.1:38218<->l=127.0.0.10:4245 (telnet_interface.c:138) SGSN_Test-Gb1-NS1(141)@fabb34539fda: Final verdict of PTC: none TC_attach_auth_sai_reject-BVCI196(139)@fabb34539fda: Final verdict of PTC: none -NSVCI98(145)@fabb34539fda: Final verdict of PTC: none SGSN_Test-Gb0-BSSGP0(137)@fabb34539fda: Final verdict of PTC: none -NSVCI97(140)@fabb34539fda: Final verdict of PTC: none -NSVCI99(150)@fabb34539fda: Final verdict of PTC: none SGSN_Test-GSUP(152)@fabb34539fda: Final verdict of PTC: none TC_attach_auth_sai_reject-BVCI220(149)@fabb34539fda: Final verdict of PTC: none SGSN_Test-Gb1-BSSGP1(142)@fabb34539fda: Final verdict of PTC: none SGSN_Test-Gb2-BSSGP2(147)@fabb34539fda: Final verdict of PTC: none [38;5;23m20240816055025507 [1;31mDLINP[0;m[38;5;23m [1;31mERROR[0;m[38;5;23m 127.0.0.103:4222 connection closed with server (ipa.c:68)[0;m [38;5;39m20240816055025507 [1;32mDLGSUP[0;m[38;5;39m [1;32mINFO[0;m[38;5;39m GSUP link to 127.0.0.103:4222 DOWN (gsup_client.c:151)[0;m -NSVCI97-provIP(138)@fabb34539fda: Final verdict of PTC: none -NSVCI98-provIP(143)@fabb34539fda: Final verdict of PTC: none SGSN_Test-GGSN_GTP(153)@fabb34539fda: Final verdict of PTC: none SGSN_Test-Gb0-NS0(136)@fabb34539fda: Final verdict of PTC: none SGSN_Test-GSUP-IPA(151)@fabb34539fda: Final verdict of PTC: none -NSVCI99-provIP(148)@fabb34539fda: Final verdict of PTC: none TC_attach_auth_sai_reject-BVCI210(144)@fabb34539fda: Final verdict of PTC: none SGSN_Test-Gb2-NS2(146)@fabb34539fda: Final verdict of PTC: none MTC@fabb34539fda: Setting final verdict of the test case. MTC@fabb34539fda: Local verdict of MTC: none MTC@fabb34539fda: Local verdict of PTC SGSN_Test-Gb0-NS0(136): none (none -> none) MTC@fabb34539fda: Local verdict of PTC SGSN_Test-Gb0-BSSGP0(137): none (none -> none) MTC@fabb34539fda: Local verdict of PTC -NSVCI97-provIP(138): none (none -> none) MTC@fabb34539fda: Local verdict of PTC TC_attach_auth_sai_reject-BVCI196(139): none (none -> none) MTC@fabb34539fda: Local verdict of PTC -NSVCI97(140): none (none -> none) MTC@fabb34539fda: Local verdict of PTC SGSN_Test-Gb1-NS1(141): none (none -> none) MTC@fabb34539fda: Local verdict of PTC SGSN_Test-Gb1-BSSGP1(142): none (none -> none) MTC@fabb34539fda: Local verdict of PTC -NSVCI98-provIP(143): none (none -> none) MTC@fabb34539fda: Local verdict of PTC TC_attach_auth_sai_reject-BVCI210(144): none (none -> none) MTC@fabb34539fda: Local verdict of PTC -NSVCI98(145): none (none -> none) MTC@fabb34539fda: Local verdict of PTC SGSN_Test-Gb2-NS2(146): none (none -> none) MTC@fabb34539fda: Local verdict of PTC SGSN_Test-Gb2-BSSGP2(147): none (none -> none) MTC@fabb34539fda: Local verdict of PTC -NSVCI99-provIP(148): none (none -> none) MTC@fabb34539fda: Local verdict of PTC TC_attach_auth_sai_reject-BVCI220(149): none (none -> none) MTC@fabb34539fda: Local verdict of PTC -NSVCI99(150): none (none -> none) MTC@fabb34539fda: Local verdict of PTC SGSN_Test-GSUP-IPA(151): none (none -> none) MTC@fabb34539fda: Local verdict of PTC SGSN_Test-GSUP(152): none (none -> none) MTC@fabb34539fda: Local verdict of PTC SGSN_Test-GGSN_GTP(153): none (none -> none) MTC@fabb34539fda: Local verdict of PTC TC_attach_auth_sai_reject(154): pass (none -> pass) MTC@fabb34539fda: Test case TC_attach_auth_sai_reject finished. Verdict: pass MTC@fabb34539fda: Starting external command `<https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test/ws/_cache/podman/os…> SGSN_Tests.TC_attach_auth_sai_reject pass'. Fri Aug 16 05:50:25 UTC 2024 [1;32m====== SGSN_Tests.TC_attach_auth_sai_reject pass ======[0m Waiting for packet dumper to finish... 0 (prev_count=-1, count=59132) [1;91m[testenv][generic] sgsn crashed![0m [1;34m[testenv][generic] Stopping testsuite (184058)[0m Error: container fabb34539fdac3c5d361078532cb9a0a344bcbe86c818e2ca941e2f4272fd8bd does not exist in database: no such container [1;91m[testenv] podman container crashed![0m [1;34m[testenv][generic] Logs saved to: https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test/2441/artifact/logs/ [0m Build step 'Execute shell' marked build as failure Recording test results [Checks API] No suitable checks publisher found.

1 0

Jenkins build is back to stable : ttcn3-sgsn-test-sns #118
by jenkins＠lists.osmocom.org 16 Aug '24

16 Aug '24

See <https://jenkins.osmocom.org/jenkins/job/ttcn3-sgsn-test-sns/118/display/red…>

1 0

2026

2025

2024

2023

2022

2021

2020

2019

jenkins-notifications