See https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs/503/display/redirect?page=changes
Changes:
[Oliver Smith] testenv: fix running configs with omitted package=
[Oliver Smith] testenv: podman_install: update can't install msg
[Pau Espin Pedrol] NGAP_Templates.ttcn: HandoverRequired: Allow passing optional Direct
------------------------------------------ [...truncated 160.57 MiB...] [32m10/08 09:32:10.201[0m: [[33msbi[0m] [1;37mDEBUG[0m: STATUS [204] (../lib/sbi/nghttp2-server.c:706) [32m10/08 09:32:10.201[0m: [[33msbi[0m] [1;37mDEBUG[0m: STREAM closed [14119] (../lib/sbi/nghttp2-server.c:1435) 0000: 00001a01 05000037 2789d161 96df3dbf .......7'..a..=. 0010: 4a01e535 112a0802 71403f71 915c0814 J..5.*..q@?q... 0020: c5a37f ... [32m10/08 09:32:10.201[0m: [[33msbi[0m] [1;37mDEBUG[0m: [204:PATCH] http://127.0.0.200:7777/nnrf-nfm/v1/nf-instances/d550c7f2-c2fa-41f1-a2b6-2f0... (../lib/sbi/client.c:744) [32m10/08 09:32:10.201[0m: [[33msbi[0m] [1;37mDEBUG[0m: RECEIVED[0] (../lib/sbi/client.c:755) [32m10/08 09:32:10.201[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): OGS_EVENT_NAME_SBI_CLIENT (../src/amf/amf-sm.c:84) [32m10/08 09:32:10.201[0m: [[33msbi[0m] [1;37mDEBUG[0m: ogs_sbi_nf_state_registered(): OGS_EVENT_NAME_SBI_CLIENT (../lib/sbi/nf-sm.c:312) MTC@4f960321ef48: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh C5G_Tests.TC_connection_inactive' was executed successfully (exit status: 0). MTC@4f960321ef48: Test case TC_connection_inactive started. GTP1U_EM(594)@4f960321ef48: Warning: sizes of 'struct sctp_event_subscribe': compile-time 14, kernel: 14 GTP1U_EM(594)@4f960321ef48: setverdict(fail): none -> fail reason: "Could not connect UECUPS socket, check your configuration", new component reason: "Could not connect UECUPS socket, check your configuration" GTP1U_EM(594)@4f960321ef48: Dynamic test case error: testcase.stop GTP1U_EM(594)@4f960321ef48: setverdict(error): fail -> error GTP1U_EM(594)@4f960321ef48: Final verdict of PTC: error [32m10/08 09:32:10.831[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2 accepted[127.0.0.202]:50000 in ng-path module (../src/amf/ngap-sctp.c:113) [32m10/08 09:32:10.831[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_ACCEPT (../src/amf/amf-sm.c:84) [32m10/08 09:32:10.831[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2 accepted[127.0.0.202] in master_sm module (../src/amf/amf-sm.c:823) TC_connection_inactive-NGAP0(595)@4f960321ef48: Warning: sizes of 'struct sctp_event_subscribe': compile-time 14, kernel: 14 [32m10/08 09:32:10.835[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_initial(): ENTRY (../src/amf/ngap-sm.c:28) [32m10/08 09:32:10.835[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): ENTRY (../src/amf/ngap-sm.c:55) [32m10/08 09:32:10.835[0m: [[33mamf[0m] [1;32mINFO[0m: [Added] Number of gNBs is now 1 (../src/amf/context.c:1332) [32m10/08 09:32:10.835[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_ASSOC_CHANGE:[T:32769, F:0x0, S:0, I/O:64/30] (../src/amf/ngap-sctp.c:152) [32m10/08 09:32:10.835[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_COMM_UP (../src/amf/ngap-sctp.c:161) [32m10/08 09:32:10.835[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_SCTP_COMM_UP (../src/amf/amf-sm.c:84) [32m10/08 09:32:10.835[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2[127.0.0.202] max_num_of_ostreams : 30 (../src/amf/amf-sm.c:870) TC_connection_inactive-NGAP1(596)@4f960321ef48: Warning: sizes of 'struct sctp_event_subscribe': compile-time 14, kernel: 14 [32m10/08 09:32:10.840[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2 accepted[127.0.0.202]:50001 in ng-path module (../src/amf/ngap-sctp.c:113) [32m10/08 09:32:10.840[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_ACCEPT (../src/amf/amf-sm.c:84) [32m10/08 09:32:10.840[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2 accepted[127.0.0.202] in master_sm module (../src/amf/amf-sm.c:823) [32m10/08 09:32:10.843[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_initial(): ENTRY (../src/amf/ngap-sm.c:28) [32m10/08 09:32:10.843[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): ENTRY (../src/amf/ngap-sm.c:55) [32m10/08 09:32:10.843[0m: [[33mamf[0m] [1;32mINFO[0m: [Added] Number of gNBs is now 2 (../src/amf/context.c:1332) [32m10/08 09:32:10.843[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_ASSOC_CHANGE:[T:32769, F:0x0, S:0, I/O:64/30] (../src/amf/ngap-sctp.c:152) [32m10/08 09:32:10.843[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_COMM_UP (../src/amf/ngap-sctp.c:161) [32m10/08 09:32:10.843[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_SCTP_COMM_UP (../src/amf/amf-sm.c:84) [32m10/08 09:32:10.843[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2[127.0.0.202] max_num_of_ostreams : 30 (../src/amf/amf-sm.c:870) [32m10/08 09:32:10.845[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_MESSAGE (../src/amf/amf-sm.c:84) [32m10/08 09:32:10.845[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): AMF_EVENT_NGAP_MESSAGE (../src/amf/ngap-sm.c:55) [32m10/08 09:32:10.845[0m: [[33mamf[0m] [1;37mDEBUG[0m: NGSetupRequest (../src/amf/ngap-handler.c:288) [32m10/08 09:32:10.845[0m: [[33mamf[0m] [1;37mDEBUG[0m: IP[127.0.0.202] GNB_ID[0x0] GNB_ID_LENGTH[22] (../src/amf/ngap-handler.c:386) [32m10/08 09:32:10.845[0m: [[33mamf[0m] [1;37mDEBUG[0m: PLMN_ID[MCC:999 MNC:70] (../src/amf/ngap-handler.c:391) [32m10/08 09:32:10.845[0m: [[33mamf[0m] [1;37mDEBUG[0m: PagingDRX[0] (../src/amf/ngap-handler.c:395) [32m10/08 09:32:10.845[0m: [[33mamf[0m] [1;37mDEBUG[0m: TAC[1] (../src/amf/ngap-handler.c:439) [32m10/08 09:32:10.845[0m: [[33mamf[0m] [1;37mDEBUG[0m: PLMN_ID[MCC:999 MNC:70] (../src/amf/ngap-handler.c:501) [32m10/08 09:32:10.845[0m: [[33mamf[0m] [1;37mDEBUG[0m: S_NSSAI[SST:1 SD:0xffffff] (../src/amf/ngap-handler.c:562) [32m10/08 09:32:10.845[0m: [[33mamf[0m] [1;37mDEBUG[0m: TAC[1] (../src/amf/ngap-handler.c:72) [32m10/08 09:32:10.845[0m: [[33mamf[0m] [1;37mDEBUG[0m: PLMN_ID[MCC:999 MNC:70] (../src/amf/ngap-handler.c:73) [32m10/08 09:32:10.845[0m: [[33mamf[0m] [1;37mDEBUG[0m: SERVED_TAI_INDEX[0] (../src/amf/ngap-handler.c:78) [32m10/08 09:32:10.845[0m: [[33mamf[0m] [1;37mDEBUG[0m: PLMN_ID[MCC:999 MNC:70] (../src/amf/ngap-handler.c:100) [32m10/08 09:32:10.845[0m: [[33mamf[0m] [1;37mDEBUG[0m: S_NSSAI[SST:1 SD:0xffffff] (../src/amf/ngap-handler.c:105) [32m10/08 09:32:10.845[0m: [[33mamf[0m] [1;37mDEBUG[0m: NG-Setup response (../src/amf/ngap-path.c:356) [32m10/08 09:32:10.845[0m: [[33mamf[0m] [1;37mDEBUG[0m: NGSetupResponse (../src/amf/ngap-build.c:91) [32m10/08 09:32:10.845[0m: [[33mamf[0m] [1;37mDEBUG[0m: IP[127.0.0.202] RAN_ID[0] (../src/amf/ngap-path.c:64) MTC@4f960321ef48: setverdict(pass): none -> pass MTC@4f960321ef48: Dynamic test case error: Error message was received from MC: The connect operation refers to test component with component reference 594, which has already terminated. MTC@4f960321ef48: setverdict(error): pass -> error TC_connection_inactive0(597)@4f960321ef48: Final verdict of PTC: none [32m10/08 09:32:10.853[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_SHUTDOWN_EVENT:[T:32773, F:0x0, L:12] (../src/amf/ngap-sctp.c:193) [32m10/08 09:32:10.853[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_SHUTDOWN_EVENT:[T:32773, F:0x0, L:12] (../src/amf/ngap-sctp.c:193) [32m10/08 09:32:10.853[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_CONNREFUSED (../src/amf/amf-sm.c:84) [32m10/08 09:32:10.853[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2[127.0.0.202] connection refused!!! (../src/amf/amf-sm.c:883) [32m10/08 09:32:10.853[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): EXIT (../src/amf/ngap-sm.c:55) [32m10/08 09:32:10.853[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_final(): EXIT (../src/amf/ngap-sm.c:37) [32m10/08 09:32:10.853[0m: [[33mamf[0m] [1;32mINFO[0m: [Removed] Number of gNBs is now 1 (../src/amf/context.c:1368) [32m10/08 09:32:10.853[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_CONNREFUSED (../src/amf/amf-sm.c:84) [32m10/08 09:32:10.853[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2[127.0.0.202] connection refused!!! (../src/amf/amf-sm.c:883) [32m10/08 09:32:10.853[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): EXIT (../src/amf/ngap-sm.c:55) [32m10/08 09:32:10.853[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_final(): EXIT (../src/amf/ngap-sm.c:37) [32m10/08 09:32:10.853[0m: [[33mamf[0m] [1;32mINFO[0m: [Removed] Number of gNBs is now 0 (../src/amf/context.c:1368) TC_connection_inactive-NGAP1(596)@4f960321ef48: Final verdict of PTC: none TC_connection_inactive-NGAP0(595)@4f960321ef48: Final verdict of PTC: none MTC@4f960321ef48: Setting final verdict of the test case. MTC@4f960321ef48: Local verdict of MTC: error MTC@4f960321ef48: Local verdict of PTC GTP1U_EM(594): error (error -> error) MTC@4f960321ef48: Local verdict of PTC TC_connection_inactive-NGAP0(595): none (error -> error) MTC@4f960321ef48: Local verdict of PTC TC_connection_inactive-NGAP1(596): none (error -> error) MTC@4f960321ef48: Local verdict of PTC TC_connection_inactive0(597): none (error -> error) MTC@4f960321ef48: Test case TC_connection_inactive finished. Verdict: error MTC@4f960321ef48: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh C5G_Tests.TC_connection_inactive error'. (09:32:10) load average: 14.19, 5.94, 5.68 [1;31m------ C5G_Tests.TC_connection_inactive error ------[0m
Waiting for packet dumper to finish... 0 (prev_count=-1, count=3432) Waiting for packet dumper to finish... 1 (prev_count=3432, count=7856) MTC@4f960321ef48: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh C5G_Tests.TC_connection_inactive error' was executed successfully (exit status: 0). MTC@4f960321ef48: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh C5G_Tests.TC_connection_suspend'. ------ C5G_Tests.TC_connection_suspend ------ (09:32:12) load average: 14.19, 5.94, 5.68 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs/503/artifact/logs/testsuite/C5G_Tests.TC_connection_suspend.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs/503/artifact/logs/testsuite/C5G_Tests.TC_connection_suspend.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 [32m10/08 09:32:13.610[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_state_operational(): SMF_EVT_N4_TIMER (../src/smf/smf-sm.c:94) [32m10/08 09:32:13.610[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_pfcp_state_associated(): SMF_EVT_N4_TIMER (../src/smf/pfcp-sm.c:182) [32m10/08 09:32:13.610[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1572] LOCAL Create peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:131) [32m10/08 09:32:13.610[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: Heartbeat Request (../lib/pfcp/build.c:28) [32m10/08 09:32:13.610[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1572] LOCAL UPD TX-1 peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:231) [32m10/08 09:32:13.610[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1572] LOCAL Commit peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:500) [32m10/08 09:32:13.611[0m: [[33mupf[0m] [1;37mDEBUG[0m: ogs_pfcp_extract_node_id() type [1] pfcp_status [1] node_id [NULL] from [127.0.0.4]:8805 (../src/upf/pfcp-path.c:101) [32m10/08 09:32:13.611[0m: [[33mupf[0m] [1;37mDEBUG[0m: Found PFCP-Node: addr_list [127.0.0.4]:8805 (../src/upf/pfcp-path.c:155) [32m10/08 09:32:13.611[0m: [[33mupf[0m] [1;37mDEBUG[0m: Merged PFCP-Node: addr_list [127.0.0.4]:8805 (../src/upf/pfcp-path.c:161) [32m10/08 09:32:13.611[0m: [[33mupf[0m] [1;37mDEBUG[0m: upf_state_operational(): UPF_EVT_N4_MESSAGE (../src/upf/upf-sm.c:51) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1572] Cannot find new type 1 from PFCP peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:767) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1572] REMOTE Create peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:196) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1572] REMOTE Receive peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:778) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1572] REMOTE UPD RX-1 peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:329) [32m10/08 09:32:13.611[0m: [[33mupf[0m] [1;37mDEBUG[0m: upf_pfcp_state_associated(): UPF_EVT_N4_MESSAGE (../src/upf/pfcp-sm.c:161) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: Heartbeat Response (../lib/pfcp/build.c:56) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1572] REMOTE UPD TX-2 peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:231) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1572] REMOTE Commit peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:500) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1572] REMOTE Delete peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:836) [32m10/08 09:32:13.611[0m: [[33mupf[0m] [1;37mDEBUG[0m: upf_state_operational(): UPF_EVT_N4_TIMER (../src/upf/upf-sm.c:51) [32m10/08 09:32:13.611[0m: [[33mupf[0m] [1;37mDEBUG[0m: upf_pfcp_state_associated(): UPF_EVT_N4_TIMER (../src/upf/pfcp-sm.c:161) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [55] LOCAL Create peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:131) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: Heartbeat Request (../lib/pfcp/build.c:28) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [55] LOCAL UPD TX-1 peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:231) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [55] LOCAL Commit peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:500) [32m10/08 09:32:13.611[0m: [[33msmf[0m] [1;37mDEBUG[0m: ogs_pfcp_extract_node_id() type [2] pfcp_status [1] node_id [NULL] from [127.0.0.7]:8805 (../src/smf/pfcp-path.c:138) [32m10/08 09:32:13.611[0m: [[33msmf[0m] [1;37mDEBUG[0m: Found PFCP-Node: addr_list [127.0.0.7]:8805 (../src/smf/pfcp-path.c:192) [32m10/08 09:32:13.611[0m: [[33msmf[0m] [1;37mDEBUG[0m: Merged PFCP-Node: addr_list [127.0.0.7]:8805 (../src/smf/pfcp-path.c:198) [32m10/08 09:32:13.611[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_state_operational(): SMF_EVT_N4_MESSAGE (../src/smf/smf-sm.c:94) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1572] LOCAL Find peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:758) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1572] LOCAL Receive peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:778) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1572] LOCAL UPD RX-2 peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:329) [32m10/08 09:32:13.611[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_pfcp_state_associated(): SMF_EVT_N4_MESSAGE (../src/smf/pfcp-sm.c:182) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1572] LOCAL Commit peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:500) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1572] LOCAL Delete peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:836) [32m10/08 09:32:13.611[0m: [[33msmf[0m] [1;37mDEBUG[0m: ogs_pfcp_extract_node_id() type [1] pfcp_status [1] node_id [NULL] from [127.0.0.7]:8805 (../src/smf/pfcp-path.c:138) [32m10/08 09:32:13.611[0m: [[33msmf[0m] [1;37mDEBUG[0m: Found PFCP-Node: addr_list [127.0.0.7]:8805 (../src/smf/pfcp-path.c:192) [32m10/08 09:32:13.611[0m: [[33msmf[0m] [1;37mDEBUG[0m: Merged PFCP-Node: addr_list [127.0.0.7]:8805 (../src/smf/pfcp-path.c:198) [32m10/08 09:32:13.611[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_state_operational(): SMF_EVT_N4_MESSAGE (../src/smf/smf-sm.c:94) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [55] Cannot find new type 1 from PFCP peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:767) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [55] REMOTE Create peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:196) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [55] REMOTE Receive peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:778) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [55] REMOTE UPD RX-1 peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:329) [32m10/08 09:32:13.611[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_pfcp_state_associated(): SMF_EVT_N4_MESSAGE (../src/smf/pfcp-sm.c:182) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: Heartbeat Response (../lib/pfcp/build.c:56) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [55] REMOTE UPD TX-2 peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:231) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [55] REMOTE Commit peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:500) [32m10/08 09:32:13.611[0m: [[33mupf[0m] [1;37mDEBUG[0m: ogs_pfcp_extract_node_id() type [2] pfcp_status [1] node_id [NULL] from [127.0.0.4]:8805 (../src/upf/pfcp-path.c:101) [32m10/08 09:32:13.611[0m: [[33mupf[0m] [1;37mDEBUG[0m: Found PFCP-Node: addr_list [127.0.0.4]:8805 (../src/upf/pfcp-path.c:155) [32m10/08 09:32:13.611[0m: [[33mupf[0m] [1;37mDEBUG[0m: Merged PFCP-Node: addr_list [127.0.0.4]:8805 (../src/upf/pfcp-path.c:161) [32m10/08 09:32:13.611[0m: [[33mupf[0m] [1;37mDEBUG[0m: upf_state_operational(): UPF_EVT_N4_MESSAGE (../src/upf/upf-sm.c:51) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [55] LOCAL Find peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:758) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [55] LOCAL Receive peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:778) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [55] LOCAL UPD RX-2 peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:329) [32m10/08 09:32:13.611[0m: [[33mupf[0m] [1;37mDEBUG[0m: upf_pfcp_state_associated(): UPF_EVT_N4_MESSAGE (../src/upf/pfcp-sm.c:161) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [55] LOCAL Commit peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:500) [32m10/08 09:32:13.612[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [55] LOCAL Delete peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:836) [32m10/08 09:32:13.611[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [55] REMOTE Delete peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:836) MTC@4f960321ef48: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh C5G_Tests.TC_connection_suspend' was executed successfully (exit status: 0). MTC@4f960321ef48: Test case TC_connection_suspend started. GTP1U_EM(598)@4f960321ef48: Warning: sizes of 'struct sctp_event_subscribe': compile-time 14, kernel: 14 GTP1U_EM(598)@4f960321ef48: setverdict(fail): none -> fail reason: "Could not connect UECUPS socket, check your configuration", new component reason: "Could not connect UECUPS socket, check your configuration" GTP1U_EM(598)@4f960321ef48: Dynamic test case error: testcase.stop GTP1U_EM(598)@4f960321ef48: setverdict(error): fail -> error GTP1U_EM(598)@4f960321ef48: Final verdict of PTC: error TC_connection_suspend-NGAP0(599)@4f960321ef48: Warning: sizes of 'struct sctp_event_subscribe': compile-time 14, kernel: 14 [32m10/08 09:32:13.910[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2 accepted[127.0.0.202]:50000 in ng-path module (../src/amf/ngap-sctp.c:113) [32m10/08 09:32:13.910[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_ACCEPT (../src/amf/amf-sm.c:84) [32m10/08 09:32:13.910[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2 accepted[127.0.0.202] in master_sm module (../src/amf/amf-sm.c:823) [32m10/08 09:32:13.916[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_initial(): ENTRY (../src/amf/ngap-sm.c:28) [32m10/08 09:32:13.916[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): ENTRY (../src/amf/ngap-sm.c:55) [32m10/08 09:32:13.916[0m: [[33mamf[0m] [1;32mINFO[0m: [Added] Number of gNBs is now 1 (../src/amf/context.c:1332) [32m10/08 09:32:13.916[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_ASSOC_CHANGE:[T:32769, F:0x0, S:0, I/O:64/30] (../src/amf/ngap-sctp.c:152) [32m10/08 09:32:13.916[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_COMM_UP (../src/amf/ngap-sctp.c:161) [32m10/08 09:32:13.916[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_SCTP_COMM_UP (../src/amf/amf-sm.c:84) [32m10/08 09:32:13.916[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2[127.0.0.202] max_num_of_ostreams : 30 (../src/amf/amf-sm.c:870) TC_connection_suspend-NGAP1(600)@4f960321ef48: Warning: sizes of 'struct sctp_event_subscribe': compile-time 14, kernel: 14 [32m10/08 09:32:13.918[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2 accepted[127.0.0.202]:50001 in ng-path module (../src/amf/ngap-sctp.c:113) [32m10/08 09:32:13.918[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_ACCEPT (../src/amf/amf-sm.c:84) [32m10/08 09:32:13.918[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2 accepted[127.0.0.202] in master_sm module (../src/amf/amf-sm.c:823) [32m10/08 09:32:13.923[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_initial(): ENTRY (../src/amf/ngap-sm.c:28) [32m10/08 09:32:13.923[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): ENTRY (../src/amf/ngap-sm.c:55) [32m10/08 09:32:13.923[0m: [[33mamf[0m] [1;32mINFO[0m: [Added] Number of gNBs is now 2 (../src/amf/context.c:1332) [32m10/08 09:32:13.923[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_ASSOC_CHANGE:[T:32769, F:0x0, S:0, I/O:64/30] (../src/amf/ngap-sctp.c:152) [32m10/08 09:32:13.923[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_COMM_UP (../src/amf/ngap-sctp.c:161) [32m10/08 09:32:13.923[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_SCTP_COMM_UP (../src/amf/amf-sm.c:84) [32m10/08 09:32:13.923[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2[127.0.0.202] max_num_of_ostreams : 30 (../src/amf/amf-sm.c:870) [32m10/08 09:32:13.925[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_MESSAGE (../src/amf/amf-sm.c:84) [32m10/08 09:32:13.925[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): AMF_EVENT_NGAP_MESSAGE (../src/amf/ngap-sm.c:55) [32m10/08 09:32:13.925[0m: [[33mamf[0m] [1;37mDEBUG[0m: NGSetupRequest (../src/amf/ngap-handler.c:288) [32m10/08 09:32:13.925[0m: [[33mamf[0m] [1;37mDEBUG[0m: IP[127.0.0.202] GNB_ID[0x0] GNB_ID_LENGTH[22] (../src/amf/ngap-handler.c:386) [32m10/08 09:32:13.925[0m: [[33mamf[0m] [1;37mDEBUG[0m: PLMN_ID[MCC:999 MNC:70] (../src/amf/ngap-handler.c:391) [32m10/08 09:32:13.925[0m: [[33mamf[0m] [1;37mDEBUG[0m: PagingDRX[0] (../src/amf/ngap-handler.c:395) [32m10/08 09:32:13.925[0m: [[33mamf[0m] [1;37mDEBUG[0m: TAC[1] (../src/amf/ngap-handler.c:439) [32m10/08 09:32:13.925[0m: [[33mamf[0m] [1;37mDEBUG[0m: PLMN_ID[MCC:999 MNC:70] (../src/amf/ngap-handler.c:501) [32m10/08 09:32:13.925[0m: [[33mamf[0m] [1;37mDEBUG[0m: S_NSSAI[SST:1 SD:0xffffff] (../src/amf/ngap-handler.c:562) [32m10/08 09:32:13.925[0m: [[33mamf[0m] [1;37mDEBUG[0m: TAC[1] (../src/amf/ngap-handler.c:72) [32m10/08 09:32:13.925[0m: [[33mamf[0m] [1;37mDEBUG[0m: PLMN_ID[MCC:999 MNC:70] (../src/amf/ngap-handler.c:73) [32m10/08 09:32:13.925[0m: [[33mamf[0m] [1;37mDEBUG[0m: SERVED_TAI_INDEX[0] (../src/amf/ngap-handler.c:78) [32m10/08 09:32:13.925[0m: [[33mamf[0m] [1;37mDEBUG[0m: PLMN_ID[MCC:999 MNC:70] (../src/amf/ngap-handler.c:100) [32m10/08 09:32:13.925[0m: [[33mamf[0m] [1;37mDEBUG[0m: S_NSSAI[SST:1 SD:0xffffff] (../src/amf/ngap-handler.c:105) [32m10/08 09:32:13.925[0m: [[33mamf[0m] [1;37mDEBUG[0m: NG-Setup response (../src/amf/ngap-path.c:356) [32m10/08 09:32:13.925[0m: [[33mamf[0m] [1;37mDEBUG[0m: NGSetupResponse (../src/amf/ngap-build.c:91) [32m10/08 09:32:13.925[0m: [[33mamf[0m] [1;37mDEBUG[0m: IP[127.0.0.202] RAN_ID[0] (../src/amf/ngap-path.c:64) MTC@4f960321ef48: setverdict(pass): none -> pass MTC@4f960321ef48: Dynamic test case error: Error message was received from MC: The connect operation refers to test component with component reference 598, which has already terminated. MTC@4f960321ef48: setverdict(error): pass -> error TC_connection_suspend0(601)@4f960321ef48: Final verdict of PTC: none [32m10/08 09:32:13.932[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_SHUTDOWN_EVENT:[T:32773, F:0x0, L:12] (../src/amf/ngap-sctp.c:193) [32m10/08 09:32:13.932[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_CONNREFUSED (../src/amf/amf-sm.c:84) [32m10/08 09:32:13.932[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2[127.0.0.202] connection refused!!! (../src/amf/amf-sm.c:883) [32m10/08 09:32:13.932[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): EXIT (../src/amf/ngap-sm.c:55) [32m10/08 09:32:13.932[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_final(): EXIT (../src/amf/ngap-sm.c:37) [32m10/08 09:32:13.932[0m: [[33mamf[0m] [1;32mINFO[0m: [Removed] Number of gNBs is now 1 (../src/amf/context.c:1368) [32m10/08 09:32:13.932[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_SHUTDOWN_EVENT:[T:32773, F:0x0, L:12] (../src/amf/ngap-sctp.c:193) [32m10/08 09:32:13.932[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_CONNREFUSED (../src/amf/amf-sm.c:84) [32m10/08 09:32:13.932[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2[127.0.0.202] connection refused!!! (../src/amf/amf-sm.c:883) [32m10/08 09:32:13.932[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): EXIT (../src/amf/ngap-sm.c:55) [32m10/08 09:32:13.932[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_final(): EXIT (../src/amf/ngap-sm.c:37) [32m10/08 09:32:13.932[0m: [[33mamf[0m] [1;32mINFO[0m: [Removed] Number of gNBs is now 0 (../src/amf/context.c:1368) TC_connection_suspend-NGAP1(600)@4f960321ef48: Final verdict of PTC: none TC_connection_suspend-NGAP0(599)@4f960321ef48: Final verdict of PTC: none MTC@4f960321ef48: Setting final verdict of the test case. MTC@4f960321ef48: Local verdict of MTC: error MTC@4f960321ef48: Local verdict of PTC GTP1U_EM(598): error (error -> error) MTC@4f960321ef48: Local verdict of PTC TC_connection_suspend-NGAP0(599): none (error -> error) MTC@4f960321ef48: Local verdict of PTC TC_connection_suspend-NGAP1(600): none (error -> error) MTC@4f960321ef48: Local verdict of PTC TC_connection_suspend0(601): none (error -> error) MTC@4f960321ef48: Test case TC_connection_suspend finished. Verdict: error MTC@4f960321ef48: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh C5G_Tests.TC_connection_suspend error'. (09:32:13) load average: 14.19, 5.94, 5.68 [1;31m------ C5G_Tests.TC_connection_suspend error ------[0m
Waiting for packet dumper to finish... 0 (prev_count=-1, count=592) Waiting for packet dumper to finish... 1 (prev_count=592, count=5016) MTC@4f960321ef48: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh C5G_Tests.TC_connection_suspend error' was executed successfully (exit status: 0). MTC@4f960321ef48: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh C5G_Tests.TC_normal_reg_emergency_services'. ------ C5G_Tests.TC_normal_reg_emergency_services ------ (09:32:16) load average: 13.37, 5.91, 5.67 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs/503/artifact/logs/testsuite/C5G_Tests.TC_normal_reg_emergency_services.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs/503/artifact/logs/testsuite/C5G_Tests.TC_normal_reg_emergency_services.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 [1;34m[testenv] Stopping podman container[0m [0;94m[testenv] + ['podman', 'kill', 'testenv-5gc-osmocom-nightly-20261008-0929-688f4e76-1'][0m testenv-5gc-osmocom-nightly-20261008-0929-688f4e76-1 [0;94m[testenv] Skipping clean up scripts, podman container has already stopped[0m [1;34m[testenv] Stopping testsuite (1535670)[0m [0;94m[testenv] feed_watchdog_loop: podman container has stopped[0m [1;34m[testenv] Logs saved to: https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs/503/artifact/logs... [0m + RC=1 + [ 1 = 0 ] + uptime + grep --color=always -o load.* [01;31m[Kload average: 13.37, 5.91, 5.67[m[K + exit 1 Build step 'Execute shell' marked build as failure Recording test results [Checks API] No suitable checks publisher found.