See https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/18/display/redirect?page=changes
Changes:
[Pau Espin Pedrol] smf: Introduce test TC_pfcp_heartbeat_timeout
[Pau Espin Pedrol] PFCP_Templates: Avoid enum2oct() conversion in PFCP_Cause
[Pau Espin Pedrol] PFCP_Templates: Avoid enum2int() conversion in Src/Dst_Iface
[Pau Espin Pedrol] PFCP_Templates: Avoid enum2int() conversion in Outer_Header_Removal
[Pau Espin Pedrol] PFCP_Templates: Avoid int2oct() conversion in PFCP_Create_PDR
[Pau Espin Pedrol] PFCP_Templates: Support passing PFCPSEReq_Flags IE to
[Pau Espin Pedrol] smf: TC_pfcp_heartbeat_timeout: Expect Delete Bearer Request
[Pau Espin Pedrol] smf: Introduce test TC_pfcp_heartbeat_recovery_timestamp
[Pau Espin Pedrol] ngap: Add dec/enc functions for
[Oliver Smith] testenv: optionally compress big ttcn3 logs
[Oliver Smith] 5gc,hss,pcrf: remove mongodb when done
[pmaier@sysmocom.de] REST_Types_JSON: fix typo in field names
------------------------------------------ [...truncated 459.64 KiB...] [32m10/16 13:09:16.822[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_wait_pfcp_establishment(): SMF_EVT_N4_MESSAGE (../src/smf/gsm-sm.c:780) [32m10/16 13:09:16.822[0m: [[33msmf[0m] [1;37mDEBUG[0m: Session Establishment Response [epc] (../src/smf/n4-handler.c:1144) [32m10/16 13:09:16.822[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [5] LOCAL Commit peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:498) [32m10/16 13:09:16.822[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [5] LOCAL Delete peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:829) [32m10/16 13:09:16.822[0m: [[33mgtp[0m] [1;32mINFO[0m: gtp_connect() [127.0.0.7]:2152 (../lib/gtp/path.c:60) [32m10/16 13:09:16.822[0m: [[33msmf[0m] [1;37mDEBUG[0m: [SMF] Create Session Response (../src/smf/s5c-build.c:55) [32m10/16 13:09:16.822[0m: [[33msmf[0m] [1;37mDEBUG[0m: SGW_S5C_TEID[0x1] SMF_N4_TEID[0x7db] (../src/smf/s5c-build.c:59) [32m10/16 13:09:16.822[0m: [[33msmf[0m] [1;37mDEBUG[0m: SGW_S5U_TEID[0x1] PGW_S5U_TEID[0x1] (../src/smf/s5c-build.c:193) [32m10/16 13:09:16.822[0m: [[33mgtp[0m] [1;37mDEBUG[0m: [3133] REMOTE UPD TX-33 peer [127.0.0.202]:2123 (../lib/gtp/xact.c:412) [32m10/16 13:09:16.822[0m: [[33mgtp[0m] [1;37mDEBUG[0m: [3133] REMOTE Commit peer [127.0.0.202]:2123 (../lib/gtp/xact.c:693) [32m10/16 13:09:16.822[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_wait_pfcp_establishment(): EXIT (../src/smf/gsm-sm.c:780) [32m10/16 13:09:16.822[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_operational(): ENTRY (../src/smf/gsm-sm.c:959) TC_createSession_deleteSession(19)@3c5c07dbfacf: f_Mutex_unlock(): mutex released @ "SMF_Session_CT_4G.ttcn":276 TC_createSession_deleteSession(19)@3c5c07dbfacf: SMF assigned UE IPv4 address: "10.45.0.2" TC_createSession_deleteSession(19)@3c5c07dbfacf: setverdict(pass): pass -> pass, component reason not changed TC_createSession_deleteSession(19)@3c5c07dbfacf: 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)@3c5c07dbfacf: 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/16 13:09:16.827[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_state_operational(): SMF_EVT_S5C_MESSAGE (../src/smf/smf-sm.c:94) [32m10/16 13:09:16.827[0m: [[33mgtp[0m] [1;37mDEBUG[0m: [3134] Cannot find xact type 36 from GTPv2 peer [127.0.0.202]:2123 (../lib/gtp/xact.c:1071) [32m10/16 13:09:16.827[0m: [[33mgtp[0m] [1;37mDEBUG[0m: [3134] REMOTE Create peer [127.0.0.202]:2123 (../lib/gtp/xact.c:275) [32m10/16 13:09:16.827[0m: [[33mgtp[0m] [1;37mDEBUG[0m: [3134] REMOTE Receive peer [127.0.0.202]:2123 (../lib/gtp/xact.c:1077) [32m10/16 13:09:16.827[0m: [[33mgtp[0m] [1;37mDEBUG[0m: [3134] REMOTE UPD RX-36 peer [127.0.0.202]:2123 (../lib/gtp/xact.c:512) [32m10/16 13:09:16.827[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_operational(): SMF_EVT_S5C_MESSAGE (../src/smf/gsm-sm.c:959) [32m10/16 13:09:16.827[0m: [[33msmf[0m] [1;37mDEBUG[0m: Delete Session Request (../src/smf/s5c-handler.c:539) [32m10/16 13:09:16.827[0m: [[33mdiam[0m] [1;37mDEBUG[0m: 'aaa.localdomain' STATE is OPEN (../lib/diameter/common/util.c:37) [32m10/16 13:09:16.827[0m: [[33mdiam[0m] [1;37mDEBUG[0m: 'ocs.localdomain' STATE is OPEN (../lib/diameter/common/util.c:37) [32m10/16 13:09:16.827[0m: [[33mdiam[0m] [1;37mDEBUG[0m: 'pcrf.localdomain' STATE is OPEN (../lib/diameter/common/util.c:37) [32m10/16 13:09:16.827[0m: [[33msmf[0m] [1;37mDEBUG[0m: SGW_S5C_TEID[0x1] SMF_N4_TEID[0x7db] (../src/smf/s5c-handler.c:586) [32m10/16 13:09:16.827[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_operational(): EXIT (../src/smf/gsm-sm.c:959) [32m10/16 13:09:16.827[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_wait_pfcp_deletion(): ENTRY (../src/smf/gsm-sm.c:2268) [32m10/16 13:09:16.827[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL Create peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:130) [32m10/16 13:09:16.827[0m: [[33msmf[0m] [1;37mDEBUG[0m: Session Deletion Request (../src/smf/n4-build.c:663) [32m10/16 13:09:16.827[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL UPD TX-54 peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:229) [32m10/16 13:09:16.827[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)@3c5c07dbfacf: 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)@3c5c07dbfacf: found destination TC_createSession_deleteSession(19) TC_createSession_deleteSession-PFCP(14)@3c5c07dbfacf: 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 := '00000000000007DB'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 := 'EE7CA07C'O }, end_time := { elementIdentifier := 76, lengthIndicator := 0, end_time := 'EE7CA07C'O }, volume_measurement := omit, duration_measurement := omit, time_of_first_packet := omit, time_of_last_packet := omit, usage_information := omit } } } } } } [32m10/16 13:09:16.828[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/16 13:09:16.828[0m: [[33msmf[0m] [1;37mDEBUG[0m: Found PFCP-Node: addr_list [127.0.0.7]:8805 (../src/smf/pfcp-path.c:192) [32m10/16 13:09:16.828[0m: [[33msmf[0m] [1;37mDEBUG[0m: Merged PFCP-Node: addr_list [127.0.0.7]:8805 (../src/smf/pfcp-path.c:198) [32m10/16 13:09:16.828[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_state_operational(): SMF_EVT_N4_MESSAGE (../src/smf/smf-sm.c:94) [32m10/16 13:09:16.828[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL Find peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:756) [32m10/16 13:09:16.828[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL Receive peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:771) [32m10/16 13:09:16.828[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL UPD RX-55 peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:327) [32m10/16 13:09:16.828[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_pfcp_state_associated(): SMF_EVT_N4_MESSAGE (../src/smf/pfcp-sm.c:182) [32m10/16 13:09:16.828[0m: [[33msmf[0m] [1;37mDEBUG[0m: smf_gsm_state_wait_pfcp_deletion(): SMF_EVT_N4_MESSAGE (../src/smf/gsm-sm.c:2268) [32m10/16 13:09:16.828[0m: [[33msmf[0m] [1;37mDEBUG[0m: Session Deletion Response [epc] (../src/smf/n4-handler.c:1518) [32m10/16 13:09:16.828[0m: [[33mpfcp[0m] [1;37mDEBUG[0m: [6] LOCAL Commit peer [127.0.0.7]:8805 (../lib/pfcp/xact.c:498) [32m10/16 13:09:16.828[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/18/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@3c5c07dbfacf: setverdict(fail): pass -> fail reason: "Timeout of T_guard", new component reason: "Timeout of T_guard" GTP2C_EM(11)@3c5c07dbfacf: Final verdict of PTC: none TC_createSession_deleteSession(16)@3c5c07dbfacf: Final verdict of PTC: none MutexDispCT-TC_createSession_deleteSession(13)@3c5c07dbfacf: Final verdict of PTC: none TC_createSession_deleteSession-PFCP(15)@3c5c07dbfacf: Final verdict of PTC: none GTP1U_EM(12)@3c5c07dbfacf: Final verdict of PTC: none TC_createSession_deleteSession(17)@3c5c07dbfacf: Final verdict of PTC: none TC_createSession_deleteSession(18)@3c5c07dbfacf: Final verdict of PTC: none TC_createSession_deleteSession-PFCP(14)@3c5c07dbfacf: Final verdict of PTC: none TC_createSession_deleteSession(19)@3c5c07dbfacf: Final verdict of PTC: pass MTC@3c5c07dbfacf: Setting final verdict of the test case. MTC@3c5c07dbfacf: Local verdict of MTC: fail reason: "Timeout of T_guard" MTC@3c5c07dbfacf: Local verdict of PTC GTP2C_EM(11): none (fail -> fail) MTC@3c5c07dbfacf: Local verdict of PTC GTP1U_EM(12): none (fail -> fail) MTC@3c5c07dbfacf: Local verdict of PTC MutexDispCT-TC_createSession_deleteSession(13): none (fail -> fail) MTC@3c5c07dbfacf: Local verdict of PTC TC_createSession_deleteSession-PFCP(14): none (fail -> fail) MTC@3c5c07dbfacf: Local verdict of PTC TC_createSession_deleteSession-PFCP(15): none (fail -> fail) MTC@3c5c07dbfacf: Local verdict of PTC TC_createSession_deleteSession(16): none (fail -> fail) MTC@3c5c07dbfacf: Local verdict of PTC TC_createSession_deleteSession(17): none (fail -> fail) MTC@3c5c07dbfacf: Local verdict of PTC TC_createSession_deleteSession(18): none (fail -> fail) MTC@3c5c07dbfacf: Local verdict of PTC TC_createSession_deleteSession(19): pass (fail -> fail) MTC@3c5c07dbfacf: Test case TC_createSession_deleteSession finished. Verdict: fail reason: Timeout of T_guard MTC@3c5c07dbfacf: 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: 2.42, 1.75, 1.44 [1;31m------ SMF_Tests.TC_createSession_deleteSession fail ------[0m
Waiting for packet dumper to finish... 0 (prev_count=-1, count=28984) MTC@3c5c07dbfacf: 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@3c5c07dbfacf: 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: 2.39, 1.76, 1.44 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/18/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_ipv6.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/18/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_ipv6.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 MTC@3c5c07dbfacf: 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@3c5c07dbfacf: Test case TC_createSession_deleteSession_ipv6 started. TC_createSession_deleteSession_ipv6-PFCP(23)@3c5c07dbfacf: f_PFCPEM_conns_bcast_add(): vc_conn mtc subscribed for broadcast TC_createSession_deleteSession_ipv6-PFCP(23)@3c5c07dbfacf: 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 := 4001145014 } } } } MTC@3c5c07dbfacf: setverdict(fail): none -> fail reason: ""PFCP_Emulation.ttcn:507 : 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:507 : 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@3c5c07dbfacf: Stopping testcase execution from "PFCP_Emulation.ttcn":507 GTP1U_EM(21)@3c5c07dbfacf: Final verdict of PTC: none GTP2C_EM(20)@3c5c07dbfacf: Final verdict of PTC: none MutexDispCT-TC_createSession_deleteSession_ipv6(22)@3c5c07dbfacf: Final verdict of PTC: none TC_createSession_deleteSession_ipv6-PFCP(23)@3c5c07dbfacf: Final verdict of PTC: none MTC@3c5c07dbfacf: Setting final verdict of the test case. MTC@3c5c07dbfacf: Local verdict of MTC: fail reason: ""PFCP_Emulation.ttcn:507 : 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@3c5c07dbfacf: Local verdict of PTC GTP2C_EM(20): none (fail -> fail) MTC@3c5c07dbfacf: Local verdict of PTC GTP1U_EM(21): none (fail -> fail) MTC@3c5c07dbfacf: Local verdict of PTC MutexDispCT-TC_createSession_deleteSession_ipv6(22): none (fail -> fail) MTC@3c5c07dbfacf: Local verdict of PTC TC_createSession_deleteSession_ipv6-PFCP(23): none (fail -> fail) MTC@3c5c07dbfacf: Test case TC_createSession_deleteSession_ipv6 finished. Verdict: fail reason: "PFCP_Emulation.ttcn:507 : 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@3c5c07dbfacf: 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: 2.07, 1.72, 1.43 [1;31m------ SMF_Tests.TC_createSession_deleteSession_ipv6 fail ------[0m
Waiting for packet dumper to finish... 0 (prev_count=-1, count=1796) MTC@3c5c07dbfacf: 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@3c5c07dbfacf: 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:32) load average: 2.07, 1.72, 1.43 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/18/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_ipv4v6.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/18/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_ipv4v6.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 MTC@3c5c07dbfacf: 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@3c5c07dbfacf: Test case TC_createSession_deleteSession_ipv4v6 started. TC_createSession_deleteSession_ipv4v6-PFCP(27)@3c5c07dbfacf: f_PFCPEM_conns_bcast_add(): vc_conn mtc subscribed for broadcast TC_createSession_deleteSession_ipv4v6-PFCP(27)@3c5c07dbfacf: 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 := 4001145033 } } } } MTC@3c5c07dbfacf: setverdict(fail): none -> fail reason: ""PFCP_Emulation.ttcn:507 : 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:507 : 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@3c5c07dbfacf: Stopping testcase execution from "PFCP_Emulation.ttcn":507 GTP2C_EM(24)@3c5c07dbfacf: Final verdict of PTC: none GTP1U_EM(25)@3c5c07dbfacf: Final verdict of PTC: none MutexDispCT-TC_createSession_deleteSession_ipv4v6(26)@3c5c07dbfacf: Final verdict of PTC: none TC_createSession_deleteSession_ipv4v6-PFCP(27)@3c5c07dbfacf: Final verdict of PTC: none MTC@3c5c07dbfacf: Setting final verdict of the test case. MTC@3c5c07dbfacf: Local verdict of MTC: fail reason: ""PFCP_Emulation.ttcn:507 : 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@3c5c07dbfacf: Local verdict of PTC GTP2C_EM(24): none (fail -> fail) MTC@3c5c07dbfacf: Local verdict of PTC GTP1U_EM(25): none (fail -> fail) MTC@3c5c07dbfacf: Local verdict of PTC MutexDispCT-TC_createSession_deleteSession_ipv4v6(26): none (fail -> fail) MTC@3c5c07dbfacf: Local verdict of PTC TC_createSession_deleteSession_ipv4v6-PFCP(27): none (fail -> fail) MTC@3c5c07dbfacf: Test case TC_createSession_deleteSession_ipv4v6 finished. Verdict: fail reason: "PFCP_Emulation.ttcn:507 : 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@3c5c07dbfacf: 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.56, 1.62, 1.41 [1;31m------ SMF_Tests.TC_createSession_deleteSession_ipv4v6 fail ------[0m
Waiting for packet dumper to finish... 0 (prev_count=-1, count=1808) MTC@3c5c07dbfacf: 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@3c5c07dbfacf: 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.56, 1.62, 1.41 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/18/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_250.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/18/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_250.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 MTC@3c5c07dbfacf: 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@3c5c07dbfacf: Test case TC_createSession_deleteSession_250 started. TC_createSession_deleteSession_250-PFCP(31)@3c5c07dbfacf: f_PFCPEM_conns_bcast_add(): vc_conn mtc subscribed for broadcast TC_createSession_deleteSession_250-PFCP(31)@3c5c07dbfacf: 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 := 4001145051 } } } } MTC@3c5c07dbfacf: setverdict(fail): none -> fail reason: ""PFCP_Emulation.ttcn:507 : 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:507 : 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@3c5c07dbfacf: Stopping testcase execution from "PFCP_Emulation.ttcn":507 GTP1U_EM(29)@3c5c07dbfacf: Final verdict of PTC: none GTP2C_EM(28)@3c5c07dbfacf: Final verdict of PTC: none MutexDispCT-TC_createSession_deleteSession_250(30)@3c5c07dbfacf: Final verdict of PTC: none TC_createSession_deleteSession_250-PFCP(31)@3c5c07dbfacf: Final verdict of PTC: none MTC@3c5c07dbfacf: Setting final verdict of the test case. MTC@3c5c07dbfacf: Local verdict of MTC: fail reason: ""PFCP_Emulation.ttcn:507 : 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@3c5c07dbfacf: Local verdict of PTC GTP2C_EM(28): none (fail -> fail) MTC@3c5c07dbfacf: Local verdict of PTC GTP1U_EM(29): none (fail -> fail) MTC@3c5c07dbfacf: Local verdict of PTC MutexDispCT-TC_createSession_deleteSession_250(30): none (fail -> fail) MTC@3c5c07dbfacf: Local verdict of PTC TC_createSession_deleteSession_250-PFCP(31): none (fail -> fail) MTC@3c5c07dbfacf: Test case TC_createSession_deleteSession_250 finished. Verdict: fail reason: "PFCP_Emulation.ttcn:507 : 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@3c5c07dbfacf: 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.53, 1.61, 1.41 [1;31m------ SMF_Tests.TC_createSession_deleteSession_250 fail ------[0m
Waiting for packet dumper to finish... 0 (prev_count=-1, count=1796) MTC@3c5c07dbfacf: 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@3c5c07dbfacf: 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: 2.05, 1.72, 1.44 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/18/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_250_ipv6.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/18/artifact/logs/testsuite/SMF_Tests.TC_createSession_deleteSession_250_ipv6.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 MTC@3c5c07dbfacf: 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@3c5c07dbfacf: Test case TC_createSession_deleteSession_250_ipv6 started. TC_createSession_deleteSession_250_ipv6-PFCP(35)@3c5c07dbfacf: f_PFCPEM_conns_bcast_add(): vc_conn mtc subscribed for broadcast TC_createSession_deleteSession_250_ipv6-PFCP(35)@3c5c07dbfacf: 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 := 4001145069 } } } } [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-20261016-1308-5fd274db-1', 'sh', '-c', 'echo; gdb --batch /usr/bin/open5gs-smfd https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/18/artifact/logs/smf/core -ex bt | tee https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/18/artifact/logs/smf/core.backtrace; echo'][0m
[New LWP 178] [New LWP 150] [New LWP 158] [New LWP 152] [New LWP 156] [New LWP 153] [New LWP 154] [New LWP 159] [New LWP 155] [New LWP 157] [New LWP 160] [New LWP 162] [New LWP 161] [New LWP 164] [New LWP 165] [New LWP 163] [New LWP 151] [New LWP 174] [New LWP 148] [New LWP 319] [New LWP 166] [New LWP 168] [New LWP 169] [New LWP 328] [New LWP 172] [New LWP 323] [New LWP 171] [New LWP 170] [New LWP 329] [New LWP 324] [New LWP 167] [New LWP 173] [New LWP 320] [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 0x00007ffbfcc86f69 in ogs_pfcp_parse_volume_measurement (volume=volume@entry=0x7ffb8d7f79b0, octet=octet@entry=0x7ffb6404b8c0) at ../lib/pfcp/types.c:591 warning: 591 ../lib/pfcp/types.c: No such file or directory [Current thread is 1 (Thread 0x7ffb8d7fa6c0 (LWP 178))] #0 0x00007ffbfcc86f69 in ogs_pfcp_parse_volume_measurement (volume=volume@entry=0x7ffb8d7f79b0, octet=octet@entry=0x7ffb6404b8c0) at ../lib/pfcp/types.c:591 #1 0x0000557eacb07886 in smf_epc_n4_handle_session_deletion_response (sess=sess@entry=0x7ffbe579c010, xact=xact@entry=0x7ffbe4f37748, rsp=rsp@entry=0x7ffb6404b7a8) at ../src/smf/n4-handler.c:1548 #2 0x0000557eacad9738 in smf_gsm_state_wait_pfcp_deletion (s=s@entry=0x7ffbe579c850, e=e@entry=0x7ffbb4000e30) at ../src/smf/gsm-sm.c:2313 #3 0x00007ffbfd85ee24 in ogs_fsm_dispatch (fsm=0x7ffbe579c850, event=0x7ffbb4000e30) at ../lib/core/ogs-fsm.c:127 #4 0x00007ffbfd85ee24 in ogs_fsm_dispatch (fsm=0x557ecd3c4238, event=0x7ffbb4000e30) at ../lib/core/ogs-fsm.c:127 #5 0x0000557eacacedc6 in smf_state_operational (s=s@entry=0x7ffb8d7f9c20, e=e@entry=0x7ffbb4000e30) at ../src/smf/smf-sm.c:441 #6 0x00007ffbfd85ee24 in ogs_fsm_dispatch (fsm=0x7ffb8d7f9c20, event=0x7ffbb4000e30) at ../lib/core/ogs-fsm.c:127 #7 0x0000557eacac0859 in smf_main (data=<optimized out>) at ../src/smf/init.c:194 #8 0x00007ffbfd854005 in thread_worker (arg=0x557ecd5fb680) at ../lib/core/ogs-thread.c:67 #9 0x00007ffbfc5be8bb in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:448 #10 0x00007ffbfc63c538 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-20261016-1308-5fd274db-1'][0m testenv-smf-osmocom-latest-20261016-1308-5fd274db-1 https://jenkins.osmocom.org/jenkins/job/ttcn3-smf-test-ogs-latest/18/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 (628215)[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/18/artifac... [0m + RC=1 + [ 1 = 0 ] + uptime + grep --color=always -o load.* [01;31m[Kload average: 1.90, 1.69, 1.44[m[K + exit 1 Build step 'Execute shell' marked build as failure Recording test results [Checks API] No suitable checks publisher found.