See https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs-latest/307/display/redirect
Changes:
------------------------------------------ [...truncated 163.46 MiB...] [32m09/15 13:45:59.078[0m: [[33msbi[0m] [1;37mDEBUG[0m: RECEIVED[0] (../lib/sbi/client.c:755) [32m09/15 13:45:59.078[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): OGS_EVENT_NAME_SBI_CLIENT (../src/amf/amf-sm.c:83) [32m09/15 13:45:59.078[0m: [[33msbi[0m] [1;37mDEBUG[0m: ogs_sbi_nf_state_registered(): OGS_EVENT_NAME_SBI_CLIENT (../lib/sbi/nf-sm.c:358) Waiting for packet dumper to start... 0 MTC@70c03bd1b648: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh C5G_Tests.TC_ue_service_request_cm_idle_inact_sess' was executed successfully (exit status: 0). MTC@70c03bd1b648: Test case TC_ue_service_request_cm_idle_inact_sess started. GTP1U_EM(578)@70c03bd1b648: Warning: sizes of 'struct sctp_event_subscribe': compile-time 14, kernel: 14 GTP1U_EM(578)@70c03bd1b648: 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(578)@70c03bd1b648: Dynamic test case error: testcase.stop GTP1U_EM(578)@70c03bd1b648: setverdict(error): fail -> error GTP1U_EM(578)@70c03bd1b648: Final verdict of PTC: error TC_ue_service_request_cm_idle_inact_sess-NGAP0(579)@70c03bd1b648: Warning: sizes of 'struct sctp_event_subscribe': compile-time 14, kernel: 14 [32m09/15 13:46:00.125[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2 accepted[127.0.0.202]:50000 in ng-path module (../src/amf/ngap-sctp.c:113) [32m09/15 13:46:00.125[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_ACCEPT (../src/amf/amf-sm.c:83) [32m09/15 13:46:00.125[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2 accepted[127.0.0.202] in master_sm module (../src/amf/amf-sm.c:818) [32m09/15 13:46:00.132[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_initial(): ENTRY (../src/amf/ngap-sm.c:28) [32m09/15 13:46:00.132[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): ENTRY (../src/amf/ngap-sm.c:55) [32m09/15 13:46:00.132[0m: [[33mamf[0m] [1;32mINFO[0m: [Added] Number of gNBs is now 1 (../src/amf/context.c:1277) [32m09/15 13:46:00.133[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) [32m09/15 13:46:00.133[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_COMM_UP (../src/amf/ngap-sctp.c:161) [32m09/15 13:46:00.133[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_SCTP_COMM_UP (../src/amf/amf-sm.c:83) [32m09/15 13:46:00.133[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2[127.0.0.202] max_num_of_ostreams : 30 (../src/amf/amf-sm.c:865) [32m09/15 13:46:00.138[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2 accepted[127.0.0.202]:50001 in ng-path module (../src/amf/ngap-sctp.c:113) [32m09/15 13:46:00.138[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_ACCEPT (../src/amf/amf-sm.c:83) [32m09/15 13:46:00.138[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2 accepted[127.0.0.202] in master_sm module (../src/amf/amf-sm.c:818) TC_ue_service_request_cm_idle_inact_sess-NGAP1(580)@70c03bd1b648: Warning: sizes of 'struct sctp_event_subscribe': compile-time 14, kernel: 14 [32m09/15 13:46:00.142[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_initial(): ENTRY (../src/amf/ngap-sm.c:28) [32m09/15 13:46:00.142[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): ENTRY (../src/amf/ngap-sm.c:55) [32m09/15 13:46:00.142[0m: [[33mamf[0m] [1;32mINFO[0m: [Added] Number of gNBs is now 2 (../src/amf/context.c:1277) [32m09/15 13:46:00.142[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) [32m09/15 13:46:00.142[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_COMM_UP (../src/amf/ngap-sctp.c:161) [32m09/15 13:46:00.142[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_SCTP_COMM_UP (../src/amf/amf-sm.c:83) [32m09/15 13:46:00.142[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2[127.0.0.202] max_num_of_ostreams : 30 (../src/amf/amf-sm.c:865) [32m09/15 13:46:00.145[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_MESSAGE (../src/amf/amf-sm.c:83) [32m09/15 13:46:00.145[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): AMF_EVENT_NGAP_MESSAGE (../src/amf/ngap-sm.c:55) [32m09/15 13:46:00.145[0m: [[33mamf[0m] [1;37mDEBUG[0m: NGSetupRequest (../src/amf/ngap-handler.c:288) [32m09/15 13:46:00.145[0m: [[33mamf[0m] [1;37mDEBUG[0m: IP[127.0.0.202] GNB_ID[0x0] GNB_ID_LENGTH[22] (../src/amf/ngap-handler.c:386) [32m09/15 13:46:00.145[0m: [[33mamf[0m] [1;37mDEBUG[0m: PLMN_ID[MCC:999 MNC:70] (../src/amf/ngap-handler.c:391) [32m09/15 13:46:00.145[0m: [[33mamf[0m] [1;37mDEBUG[0m: PagingDRX[0] (../src/amf/ngap-handler.c:395) [32m09/15 13:46:00.145[0m: [[33mamf[0m] [1;37mDEBUG[0m: TAC[1] (../src/amf/ngap-handler.c:439) [32m09/15 13:46:00.145[0m: [[33mamf[0m] [1;37mDEBUG[0m: PLMN_ID[MCC:999 MNC:70] (../src/amf/ngap-handler.c:501) [32m09/15 13:46:00.145[0m: [[33mamf[0m] [1;37mDEBUG[0m: S_NSSAI[SST:1 SD:0xffffff] (../src/amf/ngap-handler.c:562) [32m09/15 13:46:00.145[0m: [[33mamf[0m] [1;37mDEBUG[0m: TAC[1] (../src/amf/ngap-handler.c:72) [32m09/15 13:46:00.145[0m: [[33mamf[0m] [1;37mDEBUG[0m: PLMN_ID[MCC:999 MNC:70] (../src/amf/ngap-handler.c:73) [32m09/15 13:46:00.145[0m: [[33mamf[0m] [1;37mDEBUG[0m: SERVED_TAI_INDEX[0] (../src/amf/ngap-handler.c:78) [32m09/15 13:46:00.145[0m: [[33mamf[0m] [1;37mDEBUG[0m: PLMN_ID[MCC:999 MNC:70] (../src/amf/ngap-handler.c:100) [32m09/15 13:46:00.145[0m: [[33mamf[0m] [1;37mDEBUG[0m: S_NSSAI[SST:1 SD:0xffffff] (../src/amf/ngap-handler.c:105) [32m09/15 13:46:00.145[0m: [[33mamf[0m] [1;37mDEBUG[0m: NG-Setup response (../src/amf/ngap-path.c:356) [32m09/15 13:46:00.145[0m: [[33mamf[0m] [1;37mDEBUG[0m: NGSetupResponse (../src/amf/ngap-build.c:91) [32m09/15 13:46:00.145[0m: [[33mamf[0m] [1;37mDEBUG[0m: IP[127.0.0.202] RAN_ID[0] (../src/amf/ngap-path.c:64) MTC@70c03bd1b648: setverdict(pass): none -> pass MTC@70c03bd1b648: Dynamic test case error: Error message was received from MC: The connect operation refers to test component with component reference 578, which has already terminated. MTC@70c03bd1b648: setverdict(error): pass -> error TC_ue_service_request_cm_idle_inact_sess0(581)@70c03bd1b648: Final verdict of PTC: none [32m09/15 13:46:00.152[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_SHUTDOWN_EVENT:[T:32773, F:0x0, L:12] (../src/amf/ngap-sctp.c:193) [32m09/15 13:46:00.152[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_SHUTDOWN_EVENT:[T:32773, F:0x0, L:12] (../src/amf/ngap-sctp.c:193) [32m09/15 13:46:00.152[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_CONNREFUSED (../src/amf/amf-sm.c:83) [32m09/15 13:46:00.152[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2[127.0.0.202] connection refused!!! (../src/amf/amf-sm.c:878) [32m09/15 13:46:00.152[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): EXIT (../src/amf/ngap-sm.c:55) [32m09/15 13:46:00.152[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_final(): EXIT (../src/amf/ngap-sm.c:37) [32m09/15 13:46:00.152[0m: [[33mamf[0m] [1;32mINFO[0m: [Removed] Number of gNBs is now 1 (../src/amf/context.c:1305) [32m09/15 13:46:00.152[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_CONNREFUSED (../src/amf/amf-sm.c:83) [32m09/15 13:46:00.152[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2[127.0.0.202] connection refused!!! (../src/amf/amf-sm.c:878) [32m09/15 13:46:00.152[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): EXIT (../src/amf/ngap-sm.c:55) [32m09/15 13:46:00.152[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_final(): EXIT (../src/amf/ngap-sm.c:37) [32m09/15 13:46:00.152[0m: [[33mamf[0m] [1;32mINFO[0m: [Removed] Number of gNBs is now 0 (../src/amf/context.c:1305) TC_ue_service_request_cm_idle_inact_sess-NGAP1(580)@70c03bd1b648: Final verdict of PTC: none TC_ue_service_request_cm_idle_inact_sess-NGAP0(579)@70c03bd1b648: Final verdict of PTC: none MTC@70c03bd1b648: Setting final verdict of the test case. MTC@70c03bd1b648: Local verdict of MTC: error MTC@70c03bd1b648: Local verdict of PTC GTP1U_EM(578): error (error -> error) MTC@70c03bd1b648: Local verdict of PTC TC_ue_service_request_cm_idle_inact_sess-NGAP0(579): none (error -> error) MTC@70c03bd1b648: Local verdict of PTC TC_ue_service_request_cm_idle_inact_sess-NGAP1(580): none (error -> error) MTC@70c03bd1b648: Local verdict of PTC TC_ue_service_request_cm_idle_inact_sess0(581): none (error -> error) MTC@70c03bd1b648: Test case TC_ue_service_request_cm_idle_inact_sess finished. Verdict: error MTC@70c03bd1b648: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh C5G_Tests.TC_ue_service_request_cm_idle_inact_sess error'. (13:46:00) load average: 3.61, 3.82, 2.89 [1;31m------ C5G_Tests.TC_ue_service_request_cm_idle_inact_sess error ------[0m
Waiting for packet dumper to finish... 0 (prev_count=-1, count=456) [32m09/15 13:46:00.812[0m: [[33mdiam[0m] [1;37mDEBUG[0m: pid:ConnTo:pcrf.localdomain in md_hook_cb_tree@dbg_msg_dumps.c:150: CONNECT FAILED to pcrf.localdomain: All connection attempts failed, will retry later ((null):0) Waiting for packet dumper to finish... 1 (prev_count=456, count=5172) [32m09/15 13:46:01.385[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_state_operational(): SMF_EVT_N4_TIMER (../src/smf/smf-sm.c:94) [32m09/15 13:46:01.385[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_pfcp_state_associated(): SMF_EVT_N4_TIMER (../src/smf/pfcp-sm.c:182) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1571] LOCAL Create peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:130) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: Heartbeat Request (../lib/pfcp/build.c:28) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1571] LOCAL UPD TX-1 peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:229) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1571] LOCAL Commit peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:498) [32m09/15 13:46:01.385[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) [32m09/15 13:46:01.385[0m: [[33mupf[0m] [1;37mDEBUG[0m: Found PFCP-Node: addr_list [127.0.0.4]:8805 (../src/upf/pfcp-path.c:155) [32m09/15 13:46:01.385[0m: [[33mupf[0m] [1;37mDEBUG[0m: Merged PFCP-Node: addr_list [127.0.0.4]:8805 (../src/upf/pfcp-path.c:161) [32m09/15 13:46:01.385[0m: [[33mupf[0m] [1;37mDEBUG[0m: upf_state_operational(): UPF_EVT_N4_MESSAGE (../src/upf/upf-sm.c:51) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1571] Cannot find new type 1 from PFCP peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:765) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1571] REMOTE Create peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:194) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1571] REMOTE Receive peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:771) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1571] REMOTE UPD RX-1 peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:327) [32m09/15 13:46:01.385[0m: [[33mupf[0m] [1;37mDEBUG[0m: upf_pfcp_state_associated(): UPF_EVT_N4_MESSAGE (../src/upf/pfcp-sm.c:161) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: Heartbeat Response (../lib/pfcp/build.c:56) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1571] REMOTE UPD TX-2 peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:229) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1571] REMOTE Commit peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:498) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1571] REMOTE Delete peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:829) [32m09/15 13:46:01.385[0m: [[33mupf[0m] [1;37mDEBUG[0m: upf_state_operational(): UPF_EVT_N4_TIMER (../src/upf/upf-sm.c:51) [32m09/15 13:46:01.385[0m: [[33mupf[0m] [1;37mDEBUG[0m: upf_pfcp_state_associated(): UPF_EVT_N4_TIMER (../src/upf/pfcp-sm.c:161) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [126] LOCAL Create peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:130) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: Heartbeat Request (../lib/pfcp/build.c:28) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [126] LOCAL UPD TX-1 peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:229) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [126] LOCAL Commit peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:498) [32m09/15 13:46:01.385[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) [32m09/15 13:46:01.385[0m: [[33msmf[0m] [1;37mDEBUG[0m: Found PFCP-Node: addr_list [127.0.0.7]:8805 (../src/smf/pfcp-path.c:192) [32m09/15 13:46:01.385[0m: [[33msmf[0m] [1;37mDEBUG[0m: Merged PFCP-Node: addr_list [127.0.0.7]:8805 (../src/smf/pfcp-path.c:198) [32m09/15 13:46:01.385[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_state_operational(): SMF_EVT_N4_MESSAGE (../src/smf/smf-sm.c:94) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1571] LOCAL Find peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:756) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1571] LOCAL Receive peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:771) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1571] LOCAL UPD RX-2 peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:327) [32m09/15 13:46:01.385[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_pfcp_state_associated(): SMF_EVT_N4_MESSAGE (../src/smf/pfcp-sm.c:182) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1571] LOCAL Commit peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:498) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [1571] LOCAL Delete peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:829) [32m09/15 13:46:01.385[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) [32m09/15 13:46:01.385[0m: [[33msmf[0m] [1;37mDEBUG[0m: Found PFCP-Node: addr_list [127.0.0.7]:8805 (../src/smf/pfcp-path.c:192) [32m09/15 13:46:01.385[0m: [[33msmf[0m] [1;37mDEBUG[0m: Merged PFCP-Node: addr_list [127.0.0.7]:8805 (../src/smf/pfcp-path.c:198) [32m09/15 13:46:01.385[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_state_operational(): SMF_EVT_N4_MESSAGE (../src/smf/smf-sm.c:94) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [126] Cannot find new type 1 from PFCP peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:765) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [126] REMOTE Create peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:194) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [126] REMOTE Receive peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:771) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [126] REMOTE UPD RX-1 peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:327) [32m09/15 13:46:01.385[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_pfcp_state_associated(): SMF_EVT_N4_MESSAGE (../src/smf/pfcp-sm.c:182) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: Heartbeat Response (../lib/pfcp/build.c:56) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [126] REMOTE UPD TX-2 peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:229) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [126] REMOTE Commit peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:498) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [126] REMOTE Delete peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:829) [32m09/15 13:46:01.385[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) [32m09/15 13:46:01.385[0m: [[33mupf[0m] [1;37mDEBUG[0m: Found PFCP-Node: addr_list [127.0.0.4]:8805 (../src/upf/pfcp-path.c:155) [32m09/15 13:46:01.385[0m: [[33mupf[0m] [1;37mDEBUG[0m: Merged PFCP-Node: addr_list [127.0.0.4]:8805 (../src/upf/pfcp-path.c:161) [32m09/15 13:46:01.385[0m: [[33mupf[0m] [1;37mDEBUG[0m: upf_state_operational(): UPF_EVT_N4_MESSAGE (../src/upf/upf-sm.c:51) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [126] LOCAL Find peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:756) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [126] LOCAL Receive peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:771) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [126] LOCAL UPD RX-2 peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:327) [32m09/15 13:46:01.385[0m: [[33mupf[0m] [1;37mDEBUG[0m: upf_pfcp_state_associated(): UPF_EVT_N4_MESSAGE (../src/upf/pfcp-sm.c:161) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [126] LOCAL Commit peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:498) [32m09/15 13:46:01.385[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [126] LOCAL Delete peer [127.0.0.4]:8805 (../lib/pfcp/xact.c:829) MTC@70c03bd1b648: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh C5G_Tests.TC_ue_service_request_cm_idle_inact_sess error' was executed successfully (exit status: 0). MTC@70c03bd1b648: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh C5G_Tests.TC_ue_service_request_cm_idle_unknown_sess_active'. ------ C5G_Tests.TC_ue_service_request_cm_idle_unknown_sess_active ------ (13:46:02) load average: 3.61, 3.82, 2.89 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs-latest/307/artifact/logs/testsuite/C5G_Tests.TC_ue_service_request_cm_idle_unknown_sess_active.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs-latest/307/artifact/logs/testsuite/C5G_Tests.TC_ue_service_request_cm_idle_unknown_sess_active.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 MTC@70c03bd1b648: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh C5G_Tests.TC_ue_service_request_cm_idle_unknown_sess_active' was executed successfully (exit status: 0). MTC@70c03bd1b648: Test case TC_ue_service_request_cm_idle_unknown_sess_active started. GTP1U_EM(582)@70c03bd1b648: Warning: sizes of 'struct sctp_event_subscribe': compile-time 14, kernel: 14 GTP1U_EM(582)@70c03bd1b648: 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(582)@70c03bd1b648: Dynamic test case error: testcase.stop GTP1U_EM(582)@70c03bd1b648: setverdict(error): fail -> error GTP1U_EM(582)@70c03bd1b648: Final verdict of PTC: error TC_ue_service_request_cm_idle_unknown_sess_active-NGAP0(583)@70c03bd1b648: Warning: sizes of 'struct sctp_event_subscribe': compile-time 14, kernel: 14 [32m09/15 13:46:03.317[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2 accepted[127.0.0.202]:50000 in ng-path module (../src/amf/ngap-sctp.c:113) [32m09/15 13:46:03.317[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_ACCEPT (../src/amf/amf-sm.c:83) [32m09/15 13:46:03.317[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2 accepted[127.0.0.202] in master_sm module (../src/amf/amf-sm.c:818) [32m09/15 13:46:03.324[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_initial(): ENTRY (../src/amf/ngap-sm.c:28) [32m09/15 13:46:03.324[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): ENTRY (../src/amf/ngap-sm.c:55) [32m09/15 13:46:03.324[0m: [[33mamf[0m] [1;32mINFO[0m: [Added] Number of gNBs is now 1 (../src/amf/context.c:1277) [32m09/15 13:46:03.324[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) [32m09/15 13:46:03.324[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_COMM_UP (../src/amf/ngap-sctp.c:161) [32m09/15 13:46:03.324[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_SCTP_COMM_UP (../src/amf/amf-sm.c:83) [32m09/15 13:46:03.324[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2[127.0.0.202] max_num_of_ostreams : 30 (../src/amf/amf-sm.c:865) [32m09/15 13:46:03.331[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2 accepted[127.0.0.202]:50001 in ng-path module (../src/amf/ngap-sctp.c:113) [32m09/15 13:46:03.331[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_ACCEPT (../src/amf/amf-sm.c:83) [32m09/15 13:46:03.331[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2 accepted[127.0.0.202] in master_sm module (../src/amf/amf-sm.c:818) TC_ue_service_request_cm_idle_unknown_sess_active-NGAP1(584)@70c03bd1b648: Warning: sizes of 'struct sctp_event_subscribe': compile-time 14, kernel: 14 [32m09/15 13:46:03.334[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_initial(): ENTRY (../src/amf/ngap-sm.c:28) [32m09/15 13:46:03.334[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): ENTRY (../src/amf/ngap-sm.c:55) [32m09/15 13:46:03.334[0m: [[33mamf[0m] [1;32mINFO[0m: [Added] Number of gNBs is now 2 (../src/amf/context.c:1277) [32m09/15 13:46:03.334[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) [32m09/15 13:46:03.334[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_COMM_UP (../src/amf/ngap-sctp.c:161) [32m09/15 13:46:03.334[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_SCTP_COMM_UP (../src/amf/amf-sm.c:83) [32m09/15 13:46:03.334[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2[127.0.0.202] max_num_of_ostreams : 30 (../src/amf/amf-sm.c:865) [32m09/15 13:46:03.338[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_MESSAGE (../src/amf/amf-sm.c:83) [32m09/15 13:46:03.338[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): AMF_EVENT_NGAP_MESSAGE (../src/amf/ngap-sm.c:55) [32m09/15 13:46:03.338[0m: [[33mamf[0m] [1;37mDEBUG[0m: NGSetupRequest (../src/amf/ngap-handler.c:288) [32m09/15 13:46:03.338[0m: [[33mamf[0m] [1;37mDEBUG[0m: IP[127.0.0.202] GNB_ID[0x0] GNB_ID_LENGTH[22] (../src/amf/ngap-handler.c:386) [32m09/15 13:46:03.338[0m: [[33mamf[0m] [1;37mDEBUG[0m: PLMN_ID[MCC:999 MNC:70] (../src/amf/ngap-handler.c:391) [32m09/15 13:46:03.338[0m: [[33mamf[0m] [1;37mDEBUG[0m: PagingDRX[0] (../src/amf/ngap-handler.c:395) [32m09/15 13:46:03.338[0m: [[33mamf[0m] [1;37mDEBUG[0m: TAC[1] (../src/amf/ngap-handler.c:439) [32m09/15 13:46:03.338[0m: [[33mamf[0m] [1;37mDEBUG[0m: PLMN_ID[MCC:999 MNC:70] (../src/amf/ngap-handler.c:501) [32m09/15 13:46:03.338[0m: [[33mamf[0m] [1;37mDEBUG[0m: S_NSSAI[SST:1 SD:0xffffff] (../src/amf/ngap-handler.c:562) [32m09/15 13:46:03.338[0m: [[33mamf[0m] [1;37mDEBUG[0m: TAC[1] (../src/amf/ngap-handler.c:72) [32m09/15 13:46:03.338[0m: [[33mamf[0m] [1;37mDEBUG[0m: PLMN_ID[MCC:999 MNC:70] (../src/amf/ngap-handler.c:73) [32m09/15 13:46:03.338[0m: [[33mamf[0m] [1;37mDEBUG[0m: SERVED_TAI_INDEX[0] (../src/amf/ngap-handler.c:78) [32m09/15 13:46:03.338[0m: [[33mamf[0m] [1;37mDEBUG[0m: PLMN_ID[MCC:999 MNC:70] (../src/amf/ngap-handler.c:100) [32m09/15 13:46:03.338[0m: [[33mamf[0m] [1;37mDEBUG[0m: S_NSSAI[SST:1 SD:0xffffff] (../src/amf/ngap-handler.c:105) [32m09/15 13:46:03.338[0m: [[33mamf[0m] [1;37mDEBUG[0m: NG-Setup response (../src/amf/ngap-path.c:356) [32m09/15 13:46:03.338[0m: [[33mamf[0m] [1;37mDEBUG[0m: NGSetupResponse (../src/amf/ngap-build.c:91) [32m09/15 13:46:03.338[0m: [[33mamf[0m] [1;37mDEBUG[0m: IP[127.0.0.202] RAN_ID[0] (../src/amf/ngap-path.c:64) MTC@70c03bd1b648: setverdict(pass): none -> pass MTC@70c03bd1b648: Dynamic test case error: Error message was received from MC: The connect operation refers to test component with component reference 582, which has already terminated. MTC@70c03bd1b648: setverdict(error): pass -> error TC_ue_service_request_cm_idle_unknown_sess_active0(585)@70c03bd1b648: Final verdict of PTC: none [32m09/15 13:46:03.346[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_SHUTDOWN_EVENT:[T:32773, F:0x0, L:12] (../src/amf/ngap-sctp.c:193) [32m09/15 13:46:03.346[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_CONNREFUSED (../src/amf/amf-sm.c:83) [32m09/15 13:46:03.346[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2[127.0.0.202] connection refused!!! (../src/amf/amf-sm.c:878) [32m09/15 13:46:03.346[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): EXIT (../src/amf/ngap-sm.c:55) [32m09/15 13:46:03.346[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_final(): EXIT (../src/amf/ngap-sm.c:37) [32m09/15 13:46:03.346[0m: [[33mamf[0m] [1;32mINFO[0m: [Removed] Number of gNBs is now 1 (../src/amf/context.c:1305) TC_ue_service_request_cm_idle_unknown_sess_active-NGAP0(583)@70c03bd1b648: Final verdict of PTC: none [32m09/15 13:46:03.346[0m: [[33mamf[0m] [1;37mDEBUG[0m: SCTP_SHUTDOWN_EVENT:[T:32773, F:0x0, L:12] (../src/amf/ngap-sctp.c:193) [32m09/15 13:46:03.346[0m: [[33mamf[0m] [1;37mDEBUG[0m: amf_state_operational(): AMF_EVENT_NGAP_LO_CONNREFUSED (../src/amf/amf-sm.c:83) [32m09/15 13:46:03.346[0m: [[33mamf[0m] [1;32mINFO[0m: gNB-N2[127.0.0.202] connection refused!!! (../src/amf/amf-sm.c:878) [32m09/15 13:46:03.346[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_operational(): EXIT (../src/amf/ngap-sm.c:55) [32m09/15 13:46:03.346[0m: [[33mamf[0m] [1;37mDEBUG[0m: ngap_state_final(): EXIT (../src/amf/ngap-sm.c:37) [32m09/15 13:46:03.346[0m: [[33mamf[0m] [1;32mINFO[0m: [Removed] Number of gNBs is now 0 (../src/amf/context.c:1305) TC_ue_service_request_cm_idle_unknown_sess_active-NGAP1(584)@70c03bd1b648: Final verdict of PTC: none MTC@70c03bd1b648: Setting final verdict of the test case. MTC@70c03bd1b648: Local verdict of MTC: error MTC@70c03bd1b648: Local verdict of PTC GTP1U_EM(582): error (error -> error) MTC@70c03bd1b648: Local verdict of PTC TC_ue_service_request_cm_idle_unknown_sess_active-NGAP0(583): none (error -> error) MTC@70c03bd1b648: Local verdict of PTC TC_ue_service_request_cm_idle_unknown_sess_active-NGAP1(584): none (error -> error) MTC@70c03bd1b648: Local verdict of PTC TC_ue_service_request_cm_idle_unknown_sess_active0(585): none (error -> error) MTC@70c03bd1b648: Test case TC_ue_service_request_cm_idle_unknown_sess_active finished. Verdict: error MTC@70c03bd1b648: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh C5G_Tests.TC_ue_service_request_cm_idle_unknown_sess_active error'. (13:46:03) load average: 3.32, 3.76, 2.87 [1;31m------ C5G_Tests.TC_ue_service_request_cm_idle_unknown_sess_active error ------[0m
Waiting for packet dumper to finish... 0 (prev_count=-1, count=224) Waiting for packet dumper to finish... 1 (prev_count=224, count=4844) MTC@70c03bd1b648: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh C5G_Tests.TC_ue_service_request_cm_idle_unknown_sess_active error' was executed successfully (exit status: 0). MTC@70c03bd1b648: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh C5G_Tests.TC_ue_service_request_cm_connected'. ------ C5G_Tests.TC_ue_service_request_cm_connected ------ (13:46:05) load average: 3.32, 3.76, 2.87 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs-latest/307/artifact/logs/testsuite/C5G_Tests.TC_ue_service_request_cm_connected.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-5gc-test-ogs-latest/307/artifact/logs/testsuite/C5G_Tests.TC_ue_service_request_cm_connected.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-latest-20260915-1343-3ffc8ee5-1'][0m testenv-5gc-osmocom-latest-20260915-1343-3ffc8ee5-1 [0;94m[testenv] Skipping clean up scripts, podman container has already stopped[0m [1;34m[testenv] Stopping testsuite (1122421)[0m Error: container has already been removed Error: container has already been removed Error: container has already been removed [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-latest/307/artifa... [0m + RC=1 + [ 1 = 0 ] + uptime + grep --color=always -o load.* [01;31m[Kload average: 3.32, 3.76, 2.87[m[K + exit 1 Build step 'Execute shell' marked build as failure Recording test results [Checks API] No suitable checks publisher found.