See https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/13/display/redirect?page=changes
Changes:
[Pau Espin Pedrol] 5gc: Improve meaningful encoding of Source NG-RAN Node to Target NG-RAN
[Pau Espin Pedrol] 5gc: Introduce test
[Pau Espin Pedrol] 5gc: Retrieve open5gs-amfd /ue-info and validate handover metrics
[pmaier@sysmocom.de] es9p_Types_JSON: add comment about the encoding of euiccCiPKIdToBeUsed
[pmaier@sysmocom.de] esipa_Types_JSON: encode/decode euiccCiPKIdentifierToBeUsed as
[pmaier@sysmocom.de] es*_Types_JSON: use ts_responseHeader instead of manual assignments
------------------------------------------ [...truncated 460.03 KiB...] [32m10/09 13:09:16.828[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_wait_pfcp_establishment(): SMF_EVT_N4_MESSAGE (../src/smf/gsm-sm.c:780) [32m10/09 13:09:16.828[0m: [[33msmf[0m] [1;37mDEBUG[0m: Session Establishment Response [epc] (../src/smf/n4-handler.c:1144) [32m10/09 13:09:16.828[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [5] LOCAL Commit peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:498) [32m10/09 13:09:16.828[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [5] LOCAL Delete peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:829) [32m10/09 13:09:16.828[0m: [[33mgtp[0m] [1;32mINFO[0m: gtp_connect() [127.0.0.7]:2152 (../lib/gtp/path.c:60) [32m10/09 13:09:16.828[0m: [[33msmf[0m] [1;37mDEBUG[0m: [SMF] Create Session Response (../src/smf/s5c-build.c:55) [32m10/09 13:09:16.828[0m: [[33msmf[0m] [1;37mDEBUG[0m: SGW_S5C_TEID[0x1] SMF_N4_TEID[0x5c3] (../src/smf/s5c-build.c:59) [32m10/09 13:09:16.828[0m: [[33msmf[0m] [1;37mDEBUG[0m: SGW_S5U_TEID[0x1] PGW_S5U_TEID[0x1] (../src/smf/s5c-build.c:193) [32m10/09 13:09:16.828[0m: [[33mgtp[0m] [1;37mDEBUG[0m: [44986] REMOTE UPD TX-33 peer [127.0.0.202]:2123 (../lib/gtp/xact.c:412) [32m10/09 13:09:16.828[0m: [[33mgtp[0m] [1;37mDEBUG[0m: [44986] REMOTE Commit peer [127.0.0.202]:2123 (../lib/gtp/xact.c:693) [32m10/09 13:09:16.828[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_wait_pfcp_establishment(): EXIT (../src/smf/gsm-sm.c:780) [32m10/09 13:09:16.828[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_operational(): ENTRY (../src/smf/gsm-sm.c:959) TC_createSession_deleteSession(19)@a69d9235c20b: f_Mutex_unlock(): mutex released @ "SMF_Session_CT_4G.ttcn":275 TC_createSession_deleteSession(19)@a69d9235c20b: SMF assigned UE IPv4 address: "10.45.0.2" TC_createSession_deleteSession(19)@a69d9235c20b: setverdict(pass): pass -> pass, component reason not changed TC_createSession_deleteSession(19)@a69d9235c20b: EXP match: { key := { name := "ues_active", mtype := GAUGE (1), labels := omit }, val := 1 } vs exp { key := { name := "ues_active", mtype := GAUGE (1), labels := omit }, min := 1, max := 1 } TC_createSession_deleteSession(19)@a69d9235c20b: EXP match: { key := { name := "gtp2_sessions_active", mtype := GAUGE (1), labels := omit }, val := 1 } vs exp { key := { name := "gtp2_sessions_active", mtype := GAUGE (1), labels := omit }, min := 1, max := 1 } [32m10/09 13:09:16.833[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_state_operational(): SMF_EVT_S5C_MESSAGE (../src/smf/smf-sm.c:94) [32m10/09 13:09:16.833[0m: [[33mgtp[0m] [1;37mDEBUG[0m: [44987] Cannot find xact type 36 from GTPv2 peer [127.0.0.202]:2123 (../lib/gtp/xact.c:1071) [32m10/09 13:09:16.833[0m: [[33mgtp[0m] [1;37mDEBUG[0m: [44987] REMOTE Create peer [127.0.0.202]:2123 (../lib/gtp/xact.c:275) [32m10/09 13:09:16.833[0m: [[33mgtp[0m] [1;37mDEBUG[0m: [44987] REMOTE Receive peer [127.0.0.202]:2123 (../lib/gtp/xact.c:1077) [32m10/09 13:09:16.833[0m: [[33mgtp[0m] [1;37mDEBUG[0m: [44987] REMOTE UPD RX-36 peer [127.0.0.202]:2123 (../lib/gtp/xact.c:512) [32m10/09 13:09:16.833[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_operational(): SMF_EVT_S5C_MESSAGE (../src/smf/gsm-sm.c:959) [32m10/09 13:09:16.833[0m: [[33msmf[0m] [1;37mDEBUG[0m: Delete Session Request (../src/smf/s5c-handler.c:539) [32m10/09 13:09:16.833[0m: [[33mdiam[0m] [1;37mDEBUG[0m: 'aaa.localdomain' STATE is OPEN (../lib/diameter/common/util.c:37) [32m10/09 13:09:16.833[0m: [[33mdiam[0m] [1;37mDEBUG[0m: 'ocs.localdomain' STATE is OPEN (../lib/diameter/common/util.c:37) [32m10/09 13:09:16.833[0m: [[33mdiam[0m] [1;37mDEBUG[0m: 'pcrf.localdomain' STATE is OPEN (../lib/diameter/common/util.c:37) [32m10/09 13:09:16.833[0m: [[33msmf[0m] [1;37mDEBUG[0m: SGW_S5C_TEID[0x1] SMF_N4_TEID[0x5c3] (../src/smf/s5c-handler.c:586) [32m10/09 13:09:16.833[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_operational(): EXIT (../src/smf/gsm-sm.c:959) [32m10/09 13:09:16.833[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_wait_pfcp_deletion(): ENTRY (../src/smf/gsm-sm.c:2268) [32m10/09 13:09:16.833[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL Create peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:130) [32m10/09 13:09:16.833[0m: [[33msmf[0m] [1;37mDEBUG[0m: Session Deletion Request (../src/smf/n4-build.c:663) [32m10/09 13:09:16.833[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL UPD TX-54 peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:229) [32m10/09 13:09:16.833[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL Commit peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:498) TC_createSession_deleteSession-PFCP(14)@a69d9235c20b: PFCP_Emulation main() PFCP.receive: { peer := { conn_id := 1, remote_name := "127.0.0.4", remote_port := 8805 }, pdu := { s_flag := '1'B, mp := '0'B, spare := '000'B, version := 1, message_type := 54, lengthIndicator := 12, seid := '0000000000000001'O, sequence_number := 6, spare2 := '0000'B, mp_or_spare := '0000'B, message_body := { pfcp_session_deletion_request := { } } } } TC_createSession_deleteSession-PFCP(14)@a69d9235c20b: found destination TC_createSession_deleteSession(19) TC_createSession_deleteSession-PFCP(14)@a69d9235c20b: PFCP_Emulation main() CLIENT.receive from TC_createSession_deleteSession(19): { s_flag := '0'B, mp := '0'B, spare := '000'B, version := 1, message_type := 0, lengthIndicator := 0, seid := '00000000000005C3'O, sequence_number := 6, spare2 := '0000'B, mp_or_spare := '0000'B, message_body := { pfcp_session_deletion_response := { cause := { elementIdentifier := 19, lengthIndicator := 0, causeValue := '01'O }, offending_IE := omit, load_control_information := omit, overload_control_information := omit, usage_report := { { elementIdentifier := 79, lengthIndicator := 0, grouped_ie := { urr_id := { elementIdentifier := 81, lengthIndicator := 4, id_value := 1 }, ur_seqn := { elementIdentifier := 104, lengthIndicator := 0, ur_seqn := 0 }, usage_report_trigger := { elementIdentifier := 63, lengthIndicator := 0, perio := '0'B, volth := '0'B, timth := '0'B, quhti := '0'B, start_ := '0'B, stop_ := '0'B, droth := '0'B, immer := '0'B, volqu := '0'B, timqu := '0'B, liusa := '0'B, termr := '1'B, monit := '0'B, envcl := '0'B, macar := '0'B, eveth := '0'B, evequ := '0'B, tebur := '0'B, ipmjl := '0'B, quvti := '0'B, emrre := '0'B, upint := '0'B, spare7_7 := '0'B, spare7_8 := '0'B }, start_time := { elementIdentifier := 75, lengthIndicator := 0, start_time := 'EE7365FC'O }, end_time := { elementIdentifier := 76, lengthIndicator := 0, end_time := 'EE7365FC'O }, volume_measurement := omit, duration_measurement := omit, time_of_first_packet := omit, time_of_last_packet := omit, usage_information := omit } } } } } } [32m10/09 13:09:16.836[0m: [[33msmf[0m] [1;37mDEBUG[0m: ogs_pfcp_extract_node_id() type [55] pfcp_status [1] node_id [NULL] from [127.0.0.7]:8805 (../src/smf/pfcp-path.c:138) [32m10/09 13:09:16.836[0m: [[33msmf[0m] [1;37mDEBUG[0m: Found PFCP-Node: addr_list [127.0.0.7]:8805 (../src/smf/pfcp-path.c:192) [32m10/09 13:09:16.836[0m: [[33msmf[0m] [1;37mDEBUG[0m: Merged PFCP-Node: addr_list [127.0.0.7]:8805 (../src/smf/pfcp-path.c:198) [32m10/09 13:09:16.836[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_state_operational(): SMF_EVT_N4_MESSAGE (../src/smf/smf-sm.c:94) [32m10/09 13:09:16.836[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL Find peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:756) [32m10/09 13:09:16.836[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL Receive peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:771) [32m10/09 13:09:16.836[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL UPD RX-55 peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:327) [32m10/09 13:09:16.836[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_pfcp_state_associated(): SMF_EVT_N4_MESSAGE (../src/smf/pfcp-sm.c:182) [32m10/09 13:09:16.836[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_wait_pfcp_deletion(): SMF_EVT_N4_MESSAGE (../src/smf/gsm-sm.c:2268) [32m10/09 13:09:16.836[0m: [[33msmf[0m] [1;37mDEBUG[0m: Session Deletion Response [epc] (../src/smf/n4-handler.c:1518) [32m10/09 13:09:16.836[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL Commit peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:498) [32m10/09 13:09:16.836[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL Delete peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:829) Segmentation fault (core dumped) [1;34m[testenv] Looking for a coredump file[0m [0;94m[testenv] + ['file', 'https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/13/artifact/logs/smf/core'][0m [0;94m[testenv] Coredump file and execfn found[0m [1;91m[testenv] smf unexpected exit during SMF_Tests.TC_createSession_deleteSession! rc=0[0m [0;94m[testenv] Waiting until test has stopped...[0m MTC@a69d9235c20b: setverdict(fail): pass -> fail reason: "Timeout of T_guard", new component reason: "Timeout of T_guard" MutexDispCT-TC_createSession_deleteSession(13)@a69d9235c20b: Final verdict of PTC: none TC_createSession_deleteSession-PFCP(14)@a69d9235c20b: Final verdict of PTC: none GTP2C_EM(11)@a69d9235c20b: Final verdict of PTC: none GTP1U_EM(12)@a69d9235c20b: Final verdict of PTC: none TC_createSession_deleteSession(17)@a69d9235c20b: Final verdict of PTC: none TC_createSession_deleteSession-PFCP(15)@a69d9235c20b: Final verdict of PTC: none TC_createSession_deleteSession(16)@a69d9235c20b: Final verdict of PTC: none TC_createSession_deleteSession(18)@a69d9235c20b: Final verdict of PTC: none TC_createSession_deleteSession(19)@a69d9235c20b: Final verdict of PTC: pass MTC@a69d9235c20b: Setting final verdict of the test case. MTC@a69d9235c20b: Local verdict of MTC: fail reason: "Timeout of T_guard" MTC@a69d9235c20b: Local verdict of PTC GTP2C_EM(11): none (fail -> fail) MTC@a69d9235c20b: Local verdict of PTC GTP1U_EM(12): none (fail -> fail) MTC@a69d9235c20b: Local verdict of PTC MutexDispCT-TC_createSession_deleteSession(13): none (fail -> fail) MTC@a69d9235c20b: Local verdict of PTC TC_createSession_deleteSession-PFCP(14): none (fail -> fail) MTC@a69d9235c20b: Local verdict of PTC TC_createSession_deleteSession-PFCP(15): none (fail -> fail) MTC@a69d9235c20b: Local verdict of PTC TC_createSession_deleteSession(16): none (fail -> fail) MTC@a69d9235c20b: Local verdict of PTC TC_createSession_deleteSession(17): none (fail -> fail) MTC@a69d9235c20b: Local verdict of PTC TC_createSession_deleteSession(18): none (fail -> fail) MTC@a69d9235c20b: Local verdict of PTC TC_createSession_deleteSession(19): pass (fail -> fail) MTC@a69d9235c20b: Test case TC_createSession_deleteSession finished. Verdict: fail reason: Timeout of T_guard MTC@a69d9235c20b: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh SMF_Tests.TC_createSession_deleteSession fail'. (13:10:12) load average: 1.89, 1.51, 2.24 [1;31m------ SMF_Tests.TC_createSession_deleteSession fail ------[0m
Waiting for packet dumper to finish... 0 (prev_count=-1, count=28984) MTC@a69d9235c20b: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh SMF_Tests.TC_createSession_deleteSession fail' was executed successfully (exit status: 0). MTC@a69d9235c20b: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh SMF_Tests.TC_createSession_deleteSession_ipv6'. ------ SMF_Tests.TC_createSession_deleteSession_ipv6 ------ (13:10:13) load average: 1.89, 1.51, 2.24 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/13/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_ipv6.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/13/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_ipv6.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 MTC@a69d9235c20b: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh SMF_Tests.TC_createSession_deleteSession_ipv6' was executed successfully (exit status: 0). MTC@a69d9235c20b: Test case TC_createSession_deleteSession_ipv6 started. TC_createSession_deleteSession_ipv6-PFCP(23)@a69d9235c20b: f_PFCPEM_conns_bcast_add(): vc_conn mtc subscribed for broadcast TC_createSession_deleteSession_ipv6-PFCP(23)@a69d9235c20b: PFCP_Emulation main() CLIENT.receive from mtc: { s_flag := '0'B, mp := '0'B, spare := '000'B, version := 1, message_type := 0, lengthIndicator := 0, seid := omit, sequence_number := 0, spare2 := '0000'B, mp_or_spare := '0000'B, message_body := { heartbeat_request := { recovery_time_stamp := { elementIdentifier := 96, lengthIndicator := 0, time_value := 4000540214 } } } } MTC@a69d9235c20b: setverdict(fail): none -> fail reason: ""PFCP_Emulation.ttcn:504 : Timeout waiting for PFCP { s_flag := ?, mp := ?, spare := ?, version := 1, message_type := ?, lengthIndicator := ?, seid := *, sequence_number := ?, spare2 := ?, mp_or_spare := ?, message_body := { pfcp_association_setup_request := { node_id := ?, time_stamp := ?, up_function_features := *, cp_function_features := *, UP_IP_resource_list := * } } }"", new component reason: ""PFCP_Emulation.ttcn:504 : Timeout waiting for PFCP { s_flag := ?, mp := ?, spare := ?, version := 1, message_type := ?, lengthIndicator := ?, seid := *, sequence_number := ?, spare2 := ?, mp_or_spare := ?, message_body := { pfcp_association_setup_request := { node_id := ?, time_stamp := ?, up_function_features := *, cp_function_features := *, UP_IP_resource_list := * } } }"" MTC@a69d9235c20b: Stopping testcase execution from "PFCP_Emulation.ttcn":504 GTP2C_EM(20)@a69d9235c20b: Final verdict of PTC: none GTP1U_EM(21)@a69d9235c20b: Final verdict of PTC: none MutexDispCT-TC_createSession_deleteSession_ipv6(22)@a69d9235c20b: Final verdict of PTC: none TC_createSession_deleteSession_ipv6-PFCP(23)@a69d9235c20b: Final verdict of PTC: none MTC@a69d9235c20b: Setting final verdict of the test case. MTC@a69d9235c20b: Local verdict of MTC: fail reason: ""PFCP_Emulation.ttcn:504 : Timeout waiting for PFCP { s_flag := ?, mp := ?, spare := ?, version := 1, message_type := ?, lengthIndicator := ?, seid := *, sequence_number := ?, spare2 := ?, mp_or_spare := ?, message_body := { pfcp_association_setup_request := { node_id := ?, time_stamp := ?, up_function_features := *, cp_function_features := *, UP_IP_resource_list := * } } }"" MTC@a69d9235c20b: Local verdict of PTC GTP2C_EM(20): none (fail -> fail) MTC@a69d9235c20b: Local verdict of PTC GTP1U_EM(21): none (fail -> fail) MTC@a69d9235c20b: Local verdict of PTC MutexDispCT-TC_createSession_deleteSession_ipv6(22): none (fail -> fail) MTC@a69d9235c20b: Local verdict of PTC TC_createSession_deleteSession_ipv6-PFCP(23): none (fail -> fail) MTC@a69d9235c20b: Test case TC_createSession_deleteSession_ipv6 finished. Verdict: fail reason: "PFCP_Emulation.ttcn:504 : Timeout waiting for PFCP { s_flag := ?, mp := ?, spare := ?, version := 1, message_type := ?, lengthIndicator := ?, seid := *, sequence_number := ?, spare2 := ?, mp_or_spare := ?, message_body := { pfcp_association_setup_request := { node_id := ?, time_stamp := ?, up_function_features := *, cp_function_features := *, UP_IP_resource_list := * } } }" MTC@a69d9235c20b: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh SMF_Tests.TC_createSession_deleteSession_ipv6 fail'. (13:10:30) load average: 1.49, 1.44, 2.20 [1;31m------ SMF_Tests.TC_createSession_deleteSession_ipv6 fail ------[0m
Waiting for packet dumper to finish... 0 (prev_count=-1, count=1796) MTC@a69d9235c20b: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh SMF_Tests.TC_createSession_deleteSession_ipv6 fail' was executed successfully (exit status: 0). MTC@a69d9235c20b: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh SMF_Tests.TC_createSession_deleteSession_ipv4v6'. ------ SMF_Tests.TC_createSession_deleteSession_ipv4v6 ------ (13:10:31) load average: 1.49, 1.44, 2.20 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/13/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_ipv4v6.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/13/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_ipv4v6.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 MTC@a69d9235c20b: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh SMF_Tests.TC_createSession_deleteSession_ipv4v6' was executed successfully (exit status: 0). MTC@a69d9235c20b: Test case TC_createSession_deleteSession_ipv4v6 started. TC_createSession_deleteSession_ipv4v6-PFCP(27)@a69d9235c20b: f_PFCPEM_conns_bcast_add(): vc_conn mtc subscribed for broadcast TC_createSession_deleteSession_ipv4v6-PFCP(27)@a69d9235c20b: PFCP_Emulation main() CLIENT.receive from mtc: { s_flag := '0'B, mp := '0'B, spare := '000'B, version := 1, message_type := 0, lengthIndicator := 0, seid := omit, sequence_number := 0, spare2 := '0000'B, mp_or_spare := '0000'B, message_body := { heartbeat_request := { recovery_time_stamp := { elementIdentifier := 96, lengthIndicator := 0, time_value := 4000540233 } } } } MTC@a69d9235c20b: setverdict(fail): none -> fail reason: ""PFCP_Emulation.ttcn:504 : Timeout waiting for PFCP { s_flag := ?, mp := ?, spare := ?, version := 1, message_type := ?, lengthIndicator := ?, seid := *, sequence_number := ?, spare2 := ?, mp_or_spare := ?, message_body := { pfcp_association_setup_request := { node_id := ?, time_stamp := ?, up_function_features := *, cp_function_features := *, UP_IP_resource_list := * } } }"", new component reason: ""PFCP_Emulation.ttcn:504 : Timeout waiting for PFCP { s_flag := ?, mp := ?, spare := ?, version := 1, message_type := ?, lengthIndicator := ?, seid := *, sequence_number := ?, spare2 := ?, mp_or_spare := ?, message_body := { pfcp_association_setup_request := { node_id := ?, time_stamp := ?, up_function_features := *, cp_function_features := *, UP_IP_resource_list := * } } }"" MTC@a69d9235c20b: Stopping testcase execution from "PFCP_Emulation.ttcn":504 GTP1U_EM(25)@a69d9235c20b: Final verdict of PTC: none GTP2C_EM(24)@a69d9235c20b: Final verdict of PTC: none MutexDispCT-TC_createSession_deleteSession_ipv4v6(26)@a69d9235c20b: Final verdict of PTC: none TC_createSession_deleteSession_ipv4v6-PFCP(27)@a69d9235c20b: Final verdict of PTC: none MTC@a69d9235c20b: Setting final verdict of the test case. MTC@a69d9235c20b: Local verdict of MTC: fail reason: ""PFCP_Emulation.ttcn:504 : Timeout waiting for PFCP { s_flag := ?, mp := ?, spare := ?, version := 1, message_type := ?, lengthIndicator := ?, seid := *, sequence_number := ?, spare2 := ?, mp_or_spare := ?, message_body := { pfcp_association_setup_request := { node_id := ?, time_stamp := ?, up_function_features := *, cp_function_features := *, UP_IP_resource_list := * } } }"" MTC@a69d9235c20b: Local verdict of PTC GTP2C_EM(24): none (fail -> fail) MTC@a69d9235c20b: Local verdict of PTC GTP1U_EM(25): none (fail -> fail) MTC@a69d9235c20b: Local verdict of PTC MutexDispCT-TC_createSession_deleteSession_ipv4v6(26): none (fail -> fail) MTC@a69d9235c20b: Local verdict of PTC TC_createSession_deleteSession_ipv4v6-PFCP(27): none (fail -> fail) MTC@a69d9235c20b: Test case TC_createSession_deleteSession_ipv4v6 finished. Verdict: fail reason: "PFCP_Emulation.ttcn:504 : Timeout waiting for PFCP { s_flag := ?, mp := ?, spare := ?, version := 1, message_type := ?, lengthIndicator := ?, seid := *, sequence_number := ?, spare2 := ?, mp_or_spare := ?, message_body := { pfcp_association_setup_request := { node_id := ?, time_stamp := ?, up_function_features := *, cp_function_features := *, UP_IP_resource_list := * } } }" MTC@a69d9235c20b: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh SMF_Tests.TC_createSession_deleteSession_ipv4v6 fail'. (13:10:49) load average: 1.39, 1.42, 2.18 [1;31m------ SMF_Tests.TC_createSession_deleteSession_ipv4v6 fail ------[0m
Waiting for packet dumper to finish... 0 (prev_count=-1, count=1808) MTC@a69d9235c20b: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh SMF_Tests.TC_createSession_deleteSession_ipv4v6 fail' was executed successfully (exit status: 0). MTC@a69d9235c20b: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh SMF_Tests.TC_createSession_deleteSession_250'. ------ SMF_Tests.TC_createSession_deleteSession_250 ------ (13:10:50) load average: 1.28, 1.40, 2.17 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/13/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_250.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/13/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_250.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 MTC@a69d9235c20b: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh SMF_Tests.TC_createSession_deleteSession_250' was executed successfully (exit status: 0). MTC@a69d9235c20b: Test case TC_createSession_deleteSession_250 started. TC_createSession_deleteSession_250-PFCP(31)@a69d9235c20b: f_PFCPEM_conns_bcast_add(): vc_conn mtc subscribed for broadcast TC_createSession_deleteSession_250-PFCP(31)@a69d9235c20b: PFCP_Emulation main() CLIENT.receive from mtc: { s_flag := '0'B, mp := '0'B, spare := '000'B, version := 1, message_type := 0, lengthIndicator := 0, seid := omit, sequence_number := 0, spare2 := '0000'B, mp_or_spare := '0000'B, message_body := { heartbeat_request := { recovery_time_stamp := { elementIdentifier := 96, lengthIndicator := 0, time_value := 4000540251 } } } } MTC@a69d9235c20b: setverdict(fail): none -> fail reason: ""PFCP_Emulation.ttcn:504 : Timeout waiting for PFCP { s_flag := ?, mp := ?, spare := ?, version := 1, message_type := ?, lengthIndicator := ?, seid := *, sequence_number := ?, spare2 := ?, mp_or_spare := ?, message_body := { pfcp_association_setup_request := { node_id := ?, time_stamp := ?, up_function_features := *, cp_function_features := *, UP_IP_resource_list := * } } }"", new component reason: ""PFCP_Emulation.ttcn:504 : Timeout waiting for PFCP { s_flag := ?, mp := ?, spare := ?, version := 1, message_type := ?, lengthIndicator := ?, seid := *, sequence_number := ?, spare2 := ?, mp_or_spare := ?, message_body := { pfcp_association_setup_request := { node_id := ?, time_stamp := ?, up_function_features := *, cp_function_features := *, UP_IP_resource_list := * } } }"" MTC@a69d9235c20b: Stopping testcase execution from "PFCP_Emulation.ttcn":504 GTP1U_EM(29)@a69d9235c20b: Final verdict of PTC: none GTP2C_EM(28)@a69d9235c20b: Final verdict of PTC: none MutexDispCT-TC_createSession_deleteSession_250(30)@a69d9235c20b: Final verdict of PTC: none TC_createSession_deleteSession_250-PFCP(31)@a69d9235c20b: Final verdict of PTC: none MTC@a69d9235c20b: Setting final verdict of the test case. MTC@a69d9235c20b: Local verdict of MTC: fail reason: ""PFCP_Emulation.ttcn:504 : Timeout waiting for PFCP { s_flag := ?, mp := ?, spare := ?, version := 1, message_type := ?, lengthIndicator := ?, seid := *, sequence_number := ?, spare2 := ?, mp_or_spare := ?, message_body := { pfcp_association_setup_request := { node_id := ?, time_stamp := ?, up_function_features := *, cp_function_features := *, UP_IP_resource_list := * } } }"" MTC@a69d9235c20b: Local verdict of PTC GTP2C_EM(28): none (fail -> fail) MTC@a69d9235c20b: Local verdict of PTC GTP1U_EM(29): none (fail -> fail) MTC@a69d9235c20b: Local verdict of PTC MutexDispCT-TC_createSession_deleteSession_250(30): none (fail -> fail) MTC@a69d9235c20b: Local verdict of PTC TC_createSession_deleteSession_250-PFCP(31): none (fail -> fail) MTC@a69d9235c20b: Test case TC_createSession_deleteSession_250 finished. Verdict: fail reason: "PFCP_Emulation.ttcn:504 : Timeout waiting for PFCP { s_flag := ?, mp := ?, spare := ?, version := 1, message_type := ?, lengthIndicator := ?, seid := *, sequence_number := ?, spare2 := ?, mp_or_spare := ?, message_body := { pfcp_association_setup_request := { node_id := ?, time_stamp := ?, up_function_features := *, cp_function_features := *, UP_IP_resource_list := * } } }" MTC@a69d9235c20b: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh SMF_Tests.TC_createSession_deleteSession_250 fail'. (13:11:07) load average: 1.30, 1.40, 2.16 [1;31m------ SMF_Tests.TC_createSession_deleteSession_250 fail ------[0m
Waiting for packet dumper to finish... 0 (prev_count=-1, count=1796) MTC@a69d9235c20b: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh SMF_Tests.TC_createSession_deleteSession_250 fail' was executed successfully (exit status: 0). MTC@a69d9235c20b: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh SMF_Tests.TC_createSession_deleteSession_250_ipv6'. ------ SMF_Tests.TC_createSession_deleteSession_250_ipv6 ------ (13:11:08) load average: 1.30, 1.40, 2.16 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/13/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_250_ipv6.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/13/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_250_ipv6.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 MTC@a69d9235c20b: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh SMF_Tests.TC_createSession_deleteSession_250_ipv6' was executed successfully (exit status: 0). MTC@a69d9235c20b: Test case TC_createSession_deleteSession_250_ipv6 started. TC_createSession_deleteSession_250_ipv6-PFCP(35)@a69d9235c20b: f_PFCPEM_conns_bcast_add(): vc_conn mtc subscribed for broadcast TC_createSession_deleteSession_250_ipv6-PFCP(35)@a69d9235c20b: PFCP_Emulation main() CLIENT.receive from mtc: { s_flag := '0'B, mp := '0'B, spare := '000'B, version := 1, message_type := 0, lengthIndicator := 0, seid := omit, sequence_number := 0, spare2 := '0000'B, mp_or_spare := '0000'B, message_body := { heartbeat_request := { recovery_time_stamp := { elementIdentifier := 96, lengthIndicator := 0, time_value := 4000540269 } } } } [1;91m[testenv] Timeout in wait_until_test_stopped()[0m [1;34m[testenv] Running gdb to get a backtrace[0m [0;94m[testenv] + ['podman', 'exec', '-e', 'TESTENV_INSTALL_DIR=/', '-e', 'CCACHE_DIR=/home/osmocom-build/ccache/testenv', '-e', 'TESTENV_CACHE_DIR=https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/cache', '-e', 'TESTENV_SRC_DIR=https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src', '-e', 'TERM=dumb', '-e', 'PATH=https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/_testenv/data/scripts:https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/_testenv/data/scripts/qemu:https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/ws/src/osmo-ttcn3-hacks/smf:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin', '-e', 'HOME=/home/osmocom-build', '-e', 'PYTHONUNBUFFERED=1', '-t', 'testenv-smf-osmocom-latest-20261009-1308-2bf8ddb3-1', 'sh', '-c', 'echo; gdb --batch /usr/bin/open5gs-smfd https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/13/artifact/logs/smf/core -ex bt | tee https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/13/artifact/logs/smf/core.backtrace; echo'][0m
[New LWP 272] [New LWP 247] [New LWP 246] [New LWP 244] [New LWP 248] [New LWP 245] [New LWP 251] [New LWP 250] [New LWP 249] [New LWP 254] [New LWP 253] [New LWP 255] [New LWP 256] [New LWP 252] [New LWP 258] [New LWP 257] [New LWP 413] [New LWP 417] [New LWP 242] [New LWP 259] [New LWP 260] [New LWP 423] [New LWP 418] [New LWP 262] [New LWP 264] [New LWP 422] [New LWP 261] [New LWP 263] [New LWP 265] [New LWP 266] [New LWP 267] [New LWP 268] [New LWP 414] [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". Core was generated by `/usr/bin/open5gs-smfd -c open5gs-smf.yaml'. Program terminated with signal SIGSEGV, Segmentation fault.
warning: 591 ../lib/pfcp/types.c: No such file or directory #0 0x00007fa40f4cbf69 in ogs_pfcp_parse_volume_measurement (volume=volume@entry=0x7fa37f7fb9b0, octet=octet@entry=0x7fa37404b8c0) at ../lib/pfcp/types.c:591 [Current thread is 1 (Thread 0x7fa37f7fe6c0 (LWP 272))] #0 0x00007fa40f4cbf69 in ogs_pfcp_parse_volume_measurement (volume=volume@entry=0x7fa37f7fb9b0, octet=octet@entry=0x7fa37404b8c0) at ../lib/pfcp/types.c:591 #1 0x0000564ffcacf886 in smf_epc_n4_handle_session_deletion_response (sess=sess@entry=0x7fa3f7fc4010, xact=xact@entry=0x7fa3f775f748, rsp=rsp@entry=0x7fa37404b7a8) at ../src/smf/n4-handler.c:1548 #2 0x0000564ffcaa1738 in smf_gsm_state_wait_pfcp_deletion (s=s@entry=0x7fa3f7fc4850, e=e@entry=0x7fa3d0000e30) at ../src/smf/gsm-sm.c:2313 #3 0x00007fa410084e24 in ogs_fsm_dispatch (fsm=0x7fa3f7fc4850, event=0x7fa3d0000e30) at ../lib/core/ogs-fsm.c:127 #4 0x00007fa410084e24 in ogs_fsm_dispatch (fsm=0x56502a399238, event=0x7fa3d0000e30) at ../lib/core/ogs-fsm.c:127 #5 0x0000564ffca96dc6 in smf_state_operational (s=s@entry=0x7fa37f7fdc20, e=e@entry=0x7fa3d0000e30) at ../src/smf/smf-sm.c:441 #6 0x00007fa410084e24 in ogs_fsm_dispatch (fsm=0x7fa37f7fdc20, event=0x7fa3d0000e30) at ../lib/core/ogs-fsm.c:127 #7 0x0000564ffca88859 in smf_main (data=<optimized out>) at ../src/smf/init.c:194 #8 0x00007fa41007a005 in thread_worker (arg=0x56502a5d0680) at ../lib/core/ogs-thread.c:67 #9 0x00007fa40ede58bb in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:448 #10 0x00007fa40ee63538 in __GI___clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:78
[1;34m[testenv] Stopping podman container[0m [0;94m[testenv] + ['podman', 'kill', 'testenv-smf-osmocom-latest-20261009-1308-2bf8ddb3-1'][0m testenv-smf-osmocom-latest-20261009-1308-2bf8ddb3-1 https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/13/artifact/logs/smf/core: ELF 64-bit LSB core file, x86-64, version 1 (SYSV), SVR4-style, from 'open5gs-smfd -c open5gs-smf.yaml', real uid: 0, effective uid: 0, real gid: 0, effective gid: 0, execfn: '/usr/bin/open5gs-smfd', platform: 'x86_64' [1;34m[testenv] Stopping testsuite (2186055)[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-smf-test-ogs-latest/13/artifac... [0m + RC=1 + [ 1 = 0 ] + uptime + grep --color=always -o load.* [01;31m[Kload average: 1.09, 1.34, 2.13[m[K + exit 1 Build step 'Execute shell' marked build as failure Recording test results [Checks API] No suitable checks publisher found.