See https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/12/display/redirect?page=changes
Changes:
[Pau Espin Pedrol] NGAP_Templates.ttcn: HandoverRequired: Allow passing optional Direct
[pmaier@sysmocom.de] eIM_Tests: display (JSON/ASN.1) in ESipa error messages
------------------------------------------ [...truncated 456.34 KiB...] [32m10/08 13:09:17.541[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_wait_pfcp_establishment(): SMF_EVT_N4_MESSAGE (../src/smf/gsm-sm.c:780) [32m10/08 13:09:17.541[0m: [[33msmf[0m] [1;37mDEBUG[0m: Session Establishment Response [epc] (../src/smf/n4-handler.c:1144) [32m10/08 13:09:17.541[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [5] LOCAL Commit peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:498) [32m10/08 13:09:17.541[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [5] LOCAL Delete peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:829) [32m10/08 13:09:17.541[0m: [[33mgtp[0m] [1;32mINFO[0m: gtp_connect() [127.0.0.7]:2152 (../lib/gtp/path.c:60) [32m10/08 13:09:17.541[0m: [[33msmf[0m] [1;37mDEBUG[0m: [SMF] Create Session Response (../src/smf/s5c-build.c:55) [32m10/08 13:09:17.541[0m: [[33msmf[0m] [1;37mDEBUG[0m: SGW_S5C_TEID[0x1] SMF_N4_TEID[0xaf5] (../src/smf/s5c-build.c:59) [32m10/08 13:09:17.541[0m: [[33msmf[0m] [1;37mDEBUG[0m: SGW_S5U_TEID[0x1] PGW_S5U_TEID[0x1] (../src/smf/s5c-build.c:193) [32m10/08 13:09:17.541[0m: [[33mgtp[0m] [1;37mDEBUG[0m: [60327] REMOTE UPD TX-33 peer [127.0.0.202]:2123 (../lib/gtp/xact.c:412) [32m10/08 13:09:17.541[0m: [[33mgtp[0m] [1;37mDEBUG[0m: [60327] REMOTE Commit peer [127.0.0.202]:2123 (../lib/gtp/xact.c:693) [32m10/08 13:09:17.541[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_wait_pfcp_establishment(): EXIT (../src/smf/gsm-sm.c:780) [32m10/08 13:09:17.541[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_operational(): ENTRY (../src/smf/gsm-sm.c:959) TC_createSession_deleteSession(19)@dd218f52a4fc: f_Mutex_unlock(): mutex released @ "SMF_Session_CT_4G.ttcn":275 TC_createSession_deleteSession(19)@dd218f52a4fc: SMF assigned UE IPv4 address: "10.45.0.2" TC_createSession_deleteSession(19)@dd218f52a4fc: setverdict(pass): pass -> pass, component reason not changed TC_createSession_deleteSession(19)@dd218f52a4fc: 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)@dd218f52a4fc: 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/08 13:09:17.546[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_state_operational(): SMF_EVT_S5C_MESSAGE (../src/smf/smf-sm.c:94) [32m10/08 13:09:17.546[0m: [[33mgtp[0m] [1;37mDEBUG[0m: [60328] Cannot find xact type 36 from GTPv2 peer [127.0.0.202]:2123 (../lib/gtp/xact.c:1071) [32m10/08 13:09:17.546[0m: [[33mgtp[0m] [1;37mDEBUG[0m: [60328] REMOTE Create peer [127.0.0.202]:2123 (../lib/gtp/xact.c:275) [32m10/08 13:09:17.546[0m: [[33mgtp[0m] [1;37mDEBUG[0m: [60328] REMOTE Receive peer [127.0.0.202]:2123 (../lib/gtp/xact.c:1077) [32m10/08 13:09:17.546[0m: [[33mgtp[0m] [1;37mDEBUG[0m: [60328] REMOTE UPD RX-36 peer [127.0.0.202]:2123 (../lib/gtp/xact.c:512) [32m10/08 13:09:17.546[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_operational(): SMF_EVT_S5C_MESSAGE (../src/smf/gsm-sm.c:959) [32m10/08 13:09:17.546[0m: [[33msmf[0m] [1;37mDEBUG[0m: Delete Session Request (../src/smf/s5c-handler.c:539) [32m10/08 13:09:17.546[0m: [[33mdiam[0m] [1;37mDEBUG[0m: 'aaa.localdomain' STATE is OPEN (../lib/diameter/common/util.c:37) [32m10/08 13:09:17.546[0m: [[33mdiam[0m] [1;37mDEBUG[0m: 'ocs.localdomain' STATE is OPEN (../lib/diameter/common/util.c:37) [32m10/08 13:09:17.546[0m: [[33mdiam[0m] [1;37mDEBUG[0m: 'pcrf.localdomain' STATE is OPEN (../lib/diameter/common/util.c:37) [32m10/08 13:09:17.546[0m: [[33msmf[0m] [1;37mDEBUG[0m: SGW_S5C_TEID[0x1] SMF_N4_TEID[0xaf5] (../src/smf/s5c-handler.c:586) [32m10/08 13:09:17.546[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_operational(): EXIT (../src/smf/gsm-sm.c:959) [32m10/08 13:09:17.546[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_wait_pfcp_deletion(): ENTRY (../src/smf/gsm-sm.c:2268) [32m10/08 13:09:17.546[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL Create peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:130) [32m10/08 13:09:17.546[0m: [[33msmf[0m] [1;37mDEBUG[0m: Session Deletion Request (../src/smf/n4-build.c:663) [32m10/08 13:09:17.546[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL UPD TX-54 peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:229) [32m10/08 13:09:17.546[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)@dd218f52a4fc: 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)@dd218f52a4fc: found destination TC_createSession_deleteSession(19) TC_createSession_deleteSession-PFCP(14)@dd218f52a4fc: 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 := '0000000000000AF5'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 := 'EE72147D'O }, end_time := { elementIdentifier := 76, lengthIndicator := 0, end_time := 'EE72147D'O }, volume_measurement := omit, duration_measurement := omit, time_of_first_packet := omit, time_of_last_packet := omit, usage_information := omit } } } } } } [32m10/08 13:09:17.549[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/08 13:09:17.549[0m: [[33msmf[0m] [1;37mDEBUG[0m: Found PFCP-Node: addr_list [127.0.0.7]:8805 (../src/smf/pfcp-path.c:192) [32m10/08 13:09:17.549[0m: [[33msmf[0m] [1;37mDEBUG[0m: Merged PFCP-Node: addr_list [127.0.0.7]:8805 (../src/smf/pfcp-path.c:198) [32m10/08 13:09:17.549[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_state_operational(): SMF_EVT_N4_MESSAGE (../src/smf/smf-sm.c:94) [32m10/08 13:09:17.549[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL Find peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:756) [32m10/08 13:09:17.549[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL Receive peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:771) [32m10/08 13:09:17.549[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL UPD RX-55 peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:327) [32m10/08 13:09:17.549[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_pfcp_state_associated(): SMF_EVT_N4_MESSAGE (../src/smf/pfcp-sm.c:182) [32m10/08 13:09:17.549[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_wait_pfcp_deletion(): SMF_EVT_N4_MESSAGE (../src/smf/gsm-sm.c:2268) [32m10/08 13:09:17.549[0m: [[33msmf[0m] [1;37mDEBUG[0m: Session Deletion Response [epc] (../src/smf/n4-handler.c:1518) [32m10/08 13:09:17.549[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL Commit peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:498) [32m10/08 13:09:17.549[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/12/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@dd218f52a4fc: setverdict(fail): pass -> fail reason: "Timeout of T_guard", new component reason: "Timeout of T_guard" TC_createSession_deleteSession(16)@dd218f52a4fc: Final verdict of PTC: none MutexDispCT-TC_createSession_deleteSession(13)@dd218f52a4fc: Final verdict of PTC: none GTP2C_EM(11)@dd218f52a4fc: Final verdict of PTC: none TC_createSession_deleteSession(18)@dd218f52a4fc: Final verdict of PTC: none TC_createSession_deleteSession-PFCP(14)@dd218f52a4fc: Final verdict of PTC: none TC_createSession_deleteSession-PFCP(15)@dd218f52a4fc: Final verdict of PTC: none TC_createSession_deleteSession(17)@dd218f52a4fc: Final verdict of PTC: none GTP1U_EM(12)@dd218f52a4fc: Final verdict of PTC: none TC_createSession_deleteSession(19)@dd218f52a4fc: Final verdict of PTC: pass MTC@dd218f52a4fc: Setting final verdict of the test case. MTC@dd218f52a4fc: Local verdict of MTC: fail reason: "Timeout of T_guard" MTC@dd218f52a4fc: Local verdict of PTC GTP2C_EM(11): none (fail -> fail) MTC@dd218f52a4fc: Local verdict of PTC GTP1U_EM(12): none (fail -> fail) MTC@dd218f52a4fc: Local verdict of PTC MutexDispCT-TC_createSession_deleteSession(13): none (fail -> fail) MTC@dd218f52a4fc: Local verdict of PTC TC_createSession_deleteSession-PFCP(14): none (fail -> fail) MTC@dd218f52a4fc: Local verdict of PTC TC_createSession_deleteSession-PFCP(15): none (fail -> fail) MTC@dd218f52a4fc: Local verdict of PTC TC_createSession_deleteSession(16): none (fail -> fail) MTC@dd218f52a4fc: Local verdict of PTC TC_createSession_deleteSession(17): none (fail -> fail) MTC@dd218f52a4fc: Local verdict of PTC TC_createSession_deleteSession(18): none (fail -> fail) MTC@dd218f52a4fc: Local verdict of PTC TC_createSession_deleteSession(19): pass (fail -> fail) MTC@dd218f52a4fc: Test case TC_createSession_deleteSession finished. Verdict: fail reason: Timeout of T_guard MTC@dd218f52a4fc: 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:14) load average: 2.29, 1.64, 1.25 [1;31m------ SMF_Tests.TC_createSession_deleteSession fail ------[0m
Waiting for packet dumper to finish... 0 (prev_count=-1, count=25052) MTC@dd218f52a4fc: 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@dd218f52a4fc: 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:15) load average: 2.29, 1.64, 1.25 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/12/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_ipv6.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/12/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_ipv6.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 MTC@dd218f52a4fc: 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@dd218f52a4fc: Test case TC_createSession_deleteSession_ipv6 started. TC_createSession_deleteSession_ipv6-PFCP(23)@dd218f52a4fc: f_PFCPEM_conns_bcast_add(): vc_conn mtc subscribed for broadcast TC_createSession_deleteSession_ipv6-PFCP(23)@dd218f52a4fc: 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 := 4000453816 } } } } MTC@dd218f52a4fc: 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@dd218f52a4fc: Stopping testcase execution from "PFCP_Emulation.ttcn":504 GTP1U_EM(21)@dd218f52a4fc: Final verdict of PTC: none GTP2C_EM(20)@dd218f52a4fc: Final verdict of PTC: none MutexDispCT-TC_createSession_deleteSession_ipv6(22)@dd218f52a4fc: Final verdict of PTC: none TC_createSession_deleteSession_ipv6-PFCP(23)@dd218f52a4fc: Final verdict of PTC: none MTC@dd218f52a4fc: Setting final verdict of the test case. MTC@dd218f52a4fc: 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@dd218f52a4fc: Local verdict of PTC GTP2C_EM(20): none (fail -> fail) MTC@dd218f52a4fc: Local verdict of PTC GTP1U_EM(21): none (fail -> fail) MTC@dd218f52a4fc: Local verdict of PTC MutexDispCT-TC_createSession_deleteSession_ipv6(22): none (fail -> fail) MTC@dd218f52a4fc: Local verdict of PTC TC_createSession_deleteSession_ipv6-PFCP(23): none (fail -> fail) MTC@dd218f52a4fc: 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@dd218f52a4fc: 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:32) load average: 1.76, 1.57, 1.24 [1;31m------ SMF_Tests.TC_createSession_deleteSession_ipv6 fail ------[0m
Waiting for packet dumper to finish... 0 (prev_count=-1, count=1796) MTC@dd218f52a4fc: 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@dd218f52a4fc: 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:33) load average: 1.76, 1.57, 1.24 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/12/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_ipv4v6.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/12/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_ipv4v6.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 MTC@dd218f52a4fc: 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@dd218f52a4fc: Test case TC_createSession_deleteSession_ipv4v6 started. TC_createSession_deleteSession_ipv4v6-PFCP(27)@dd218f52a4fc: f_PFCPEM_conns_bcast_add(): vc_conn mtc subscribed for broadcast TC_createSession_deleteSession_ipv4v6-PFCP(27)@dd218f52a4fc: 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 := 4000453834 } } } } MTC@dd218f52a4fc: 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@dd218f52a4fc: Stopping testcase execution from "PFCP_Emulation.ttcn":504 GTP1U_EM(25)@dd218f52a4fc: Final verdict of PTC: none GTP2C_EM(24)@dd218f52a4fc: Final verdict of PTC: none MutexDispCT-TC_createSession_deleteSession_ipv4v6(26)@dd218f52a4fc: Final verdict of PTC: none TC_createSession_deleteSession_ipv4v6-PFCP(27)@dd218f52a4fc: Final verdict of PTC: none MTC@dd218f52a4fc: Setting final verdict of the test case. MTC@dd218f52a4fc: 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@dd218f52a4fc: Local verdict of PTC GTP2C_EM(24): none (fail -> fail) MTC@dd218f52a4fc: Local verdict of PTC GTP1U_EM(25): none (fail -> fail) MTC@dd218f52a4fc: Local verdict of PTC MutexDispCT-TC_createSession_deleteSession_ipv4v6(26): none (fail -> fail) MTC@dd218f52a4fc: Local verdict of PTC TC_createSession_deleteSession_ipv4v6-PFCP(27): none (fail -> fail) MTC@dd218f52a4fc: 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@dd218f52a4fc: 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:50) load average: 1.68, 1.56, 1.24 [1;31m------ SMF_Tests.TC_createSession_deleteSession_ipv4v6 fail ------[0m
Waiting for packet dumper to finish... 0 (prev_count=-1, count=2072) MTC@dd218f52a4fc: 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@dd218f52a4fc: 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:51) load average: 1.87, 1.60, 1.25 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/12/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_250.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/12/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_250.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 MTC@dd218f52a4fc: 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@dd218f52a4fc: Test case TC_createSession_deleteSession_250 started. TC_createSession_deleteSession_250-PFCP(31)@dd218f52a4fc: f_PFCPEM_conns_bcast_add(): vc_conn mtc subscribed for broadcast TC_createSession_deleteSession_250-PFCP(31)@dd218f52a4fc: 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 := 4000453852 } } } } MTC@dd218f52a4fc: 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@dd218f52a4fc: Stopping testcase execution from "PFCP_Emulation.ttcn":504 GTP1U_EM(29)@dd218f52a4fc: Final verdict of PTC: none GTP2C_EM(28)@dd218f52a4fc: Final verdict of PTC: none MutexDispCT-TC_createSession_deleteSession_250(30)@dd218f52a4fc: Final verdict of PTC: none TC_createSession_deleteSession_250-PFCP(31)@dd218f52a4fc: Final verdict of PTC: none MTC@dd218f52a4fc: Setting final verdict of the test case. MTC@dd218f52a4fc: 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@dd218f52a4fc: Local verdict of PTC GTP2C_EM(28): none (fail -> fail) MTC@dd218f52a4fc: Local verdict of PTC GTP1U_EM(29): none (fail -> fail) MTC@dd218f52a4fc: Local verdict of PTC MutexDispCT-TC_createSession_deleteSession_250(30): none (fail -> fail) MTC@dd218f52a4fc: Local verdict of PTC TC_createSession_deleteSession_250-PFCP(31): none (fail -> fail) MTC@dd218f52a4fc: 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@dd218f52a4fc: 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:08) load average: 1.61, 1.55, 1.24 [1;31m------ SMF_Tests.TC_createSession_deleteSession_250 fail ------[0m
Waiting for packet dumper to finish... 0 (prev_count=-1, count=1796) MTC@dd218f52a4fc: 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@dd218f52a4fc: 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:09) load average: 1.61, 1.55, 1.24 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/12/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_250_ipv6.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/12/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_250_ipv6.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 MTC@dd218f52a4fc: 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@dd218f52a4fc: Test case TC_createSession_deleteSession_250_ipv6 started. TC_createSession_deleteSession_250_ipv6-PFCP(35)@dd218f52a4fc: f_PFCPEM_conns_bcast_add(): vc_conn mtc subscribed for broadcast TC_createSession_deleteSession_250_ipv6-PFCP(35)@dd218f52a4fc: 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 := 4000453871 } } } } [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-20261008-1308-8e0614ae-1', 'sh', '-c', 'echo; gdb --batch /usr/bin/open5gs-smfd https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/12/artifact/logs/smf/core -ex bt | tee https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/12/artifact/logs/smf/core.backtrace; echo'][0m
[New LWP 271] [New LWP 243] [New LWP 247] [New LWP 248] [New LWP 244] [New LWP 250] [New LWP 245] [New LWP 249] [New LWP 246] [New LWP 251] [New LWP 252] [New LWP 253] [New LWP 254] [New LWP 255] [New LWP 256] [New LWP 258] [New LWP 261] [New LWP 257] [New LWP 241] [New LWP 260] [New LWP 259] [New LWP 267] [New LWP 263] [New LWP 262] [New LWP 419] [New LWP 264] [New LWP 415] [New LWP 414] [New LWP 423] [New LWP 265] [New LWP 418] [New LWP 422] [New LWP 266] [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.
#0 0x00007f104f966f69 in ogs_pfcp_parse_volume_measurement (volume=volume@entry=0x7f0fe4ff69b0, octet=octet@entry=0x7f0fb8017a60) at ../lib/pfcp/types.c:591 warning: 591 ../lib/pfcp/types.c: No such file or directory [Current thread is 1 (Thread 0x7f0fe4ff96c0 (LWP 271))] #0 0x00007f104f966f69 in ogs_pfcp_parse_volume_measurement (volume=volume@entry=0x7f0fe4ff69b0, octet=octet@entry=0x7f0fb8017a60) at ../lib/pfcp/types.c:591 #1 0x000055699394e886 in smf_epc_n4_handle_session_deletion_response (sess=sess@entry=0x7f10388cc010, xact=xact@entry=0x7f1038067748, rsp=rsp@entry=0x7f0fb8017948) at ../src/smf/n4-handler.c:1548 #2 0x0000556993920738 in smf_gsm_state_wait_pfcp_deletion (s=s@entry=0x7f10388cc850, e=e@entry=0x7f0fb800bc20) at ../src/smf/gsm-sm.c:2313 #3 0x00007f105098ce24 in ogs_fsm_dispatch (fsm=0x7f10388cc850, event=0x7f0fb800bc20) at ../lib/core/ogs-fsm.c:127 #4 0x00007f105098ce24 in ogs_fsm_dispatch (fsm=0x5569c4bc0238, event=0x7f0fb800bc20) at ../lib/core/ogs-fsm.c:127 #5 0x0000556993915dc6 in smf_state_operational (s=s@entry=0x7f0fe4ff8c20, e=e@entry=0x7f0fb800bc20) at ../src/smf/smf-sm.c:441 #6 0x00007f105098ce24 in ogs_fsm_dispatch (fsm=0x7f0fe4ff8c20, event=0x7f0fb800bc20) at ../lib/core/ogs-fsm.c:127 #7 0x0000556993907859 in smf_main (data=<optimized out>) at ../src/smf/init.c:194 #8 0x00007f1050982005 in thread_worker (arg=0x5569c4df7680) at ../lib/core/ogs-thread.c:67 #9 0x00007f104f7008bb in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:448 #10 0x00007f104f77e538 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-20261008-1308-8e0614ae-1'][0m testenv-smf-osmocom-latest-20261008-1308-8e0614ae-1 https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/12/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 (2846931)[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/12/artifac... [0m + RC=1 + [ 1 = 0 ] + uptime + grep --color=always -o load.* [01;31m[Kload average: 1.36, 1.50, 1.23[m[K + exit 1 Build step 'Execute shell' marked build as failure Recording test results [Checks API] No suitable checks publisher found.