See https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test/1389/display/redirect?page=changes
Changes:
[laforge] msc: fix a race condition in f_mt_call_establish()
------------------------------------------ [...truncated 500.90 KiB...] [1;33m20241128090939724 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m rest2main_read_cb(op=0x7f1ae0001460) from 139753629112896 (rest_it_op.c:93)[0;m [1;35m20241128090939724 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-43)[0x564915ffd640]{ACTIVE}: Received Event DELETE (cbc_message.c:144)[0;m [1;35m20241128090939724 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-43)[0x564915ffd640]{ACTIVE}: State change to WAIT_DELETE_ACK (T3, 15s) (smscb_message_fsm.c:128)[0;m [1;32m20241128090939724 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-43-ttcn3-mme-server)[0x564915fff320]{ACTIVE}: Received Event DELETE (smscb_message_fsm.c:130)[0;m [1;32m20241128090939724 [1;33mDSBcAP[0;m[1;32m [1;33mNOTICE[0;m[1;32m ttcn3-mme-server: Cannot transmit msg Stop-Warning-Request: reconnecting (sbcap_link.c:402)[0;m [1;32m20241128090939724 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-43-ttcn3-mme-server)[0x564915fff320]{ACTIVE}: State change to WAIT_DELETE_ACK (T3, 10s) (sbcap_smscb_peer_fsm.c:278)[0;m [1;32m20241128090939724 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-43-ttcn3-mme-server)[0x564915fff320]{WAIT_DELETE_ACK}: State change to DELETED (no timeout) (sbcap_smscb_peer_fsm.c:242)[0;m [1;35m20241128090939724 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-43)[0x564915ffd640]{WAIT_DELETE_ACK}: Received Event DELETE_NACK (sbcap_smscb_peer_fsm.c:243)[0;m [1;32m20241128090939724 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-43-ttcn3-mme-client)[0x564915fff0b0]{ACTIVE}: Received Event DELETE (smscb_message_fsm.c:130)[0;m [1;32m20241128090939724 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m ttcn3-mme-client: Tx msg Stop-Warning-Request (sbcap_link.c:408)[0;m [1;32m20241128090939725 [1;34mDSBcAP[0;m[1;32m [1;34mDEBUG[0;m[1;32m ttcn3-mme-client: Encoded message Stop-Warning-Request: 00 01 00 0f 00 00 02 00 05 00 02 00 2b 00 0b 00 02 41 70 (sbcap_link.c:416)[0;m [1;32m20241128090939725 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-43-ttcn3-mme-client)[0x564915fff0b0]{ACTIVE}: State change to WAIT_DELETE_ACK (T3, 10s) (sbcap_smscb_peer_fsm.c:278)[0;m [1;31m20241128090939725 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-43-ttcn3-bsc-server)[0x564915ffeef0]{ACTIVE}: Received Event DELETE (smscb_message_fsm.c:130)[0;m [1;31m20241128090939725 [1;33mDCBSP[0;m[1;31m [1;33mNOTICE[0;m[1;31m ttcn3-bsc-server: Cannot transmit KILL: reconnecting (cbsp_link.c:335)[0;m [1;31m20241128090939725 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-43-ttcn3-bsc-server)[0x564915ffeef0]{ACTIVE}: State change to WAIT_DELETE_ACK (T3, 10s) (cbsp_smscb_peer_fsm.c:490)[0;m [1;31m20241128090939725 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-43-ttcn3-bsc-server)[0x564915ffeef0]{WAIT_DELETE_ACK}: State change to DELETED (no timeout) (cbsp_smscb_peer_fsm.c:451)[0;m [1;35m20241128090939725 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-43)[0x564915ffd640]{WAIT_DELETE_ACK}: Received Event DELETE_ACK (cbsp_smscb_peer_fsm.c:452)[0;m [1;31m20241128090939725 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-43-ttcn3-bsc-client)[0x564915ffd770]{ACTIVE}: Received Event DELETE (smscb_message_fsm.c:130)[0;m [1;31m20241128090939725 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m ttcn3-bsc-client: Transmitting KILL (cbsp_link.c:341)[0;m [1;31m20241128090939725 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-43-ttcn3-bsc-client)[0x564915ffd770]{ACTIVE}: State change to WAIT_DELETE_ACK (T3, 10s) (cbsp_smscb_peer_fsm.c:490)[0;m TC_ecbe_create_delete_bsc_and_mme-MME0-MME0(24)@1dc49bd4234e: received expected req:{ connId := 1, remName := "127.0.0.20", remPort := 29168, locName := "127.0.0.100", locPort := 16000, msg := { initiatingMessage := { procedureCode := 1, criticality := reject (0), value_ := { stop_Warning_Request := { protocolIEs := { { id := 5, criticality := reject (0), value_ := { message_Identifier := '0000000000101011'B } }, { id := 11, criticality := reject (0), value_ := { serial_Number := '0100000101110000'B } } }, protocolExtensions := omit } } } } } [1;31m20241128090939728 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m ttcn3-bsc-client: read_cb rx_msg=(nil) (cbsp_link.c:203)[0;m [1;31m20241128090939728 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m ttcn3-bsc-client: Received CBSP [L1]> 05 00 00 21 [L2]> 0e 00 2b 02 41 70 04 00 16 00 09 f1 07 00 17 00 2a 09 f1 07 00 18 00 2a 09 f1 07 00 18 00 2b 12 00 (cbsp_link.c:222)[0;m [1;31m20241128090939728 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m ttcn3-bsc-client: Received CBSP KILL COMPLETE (cbsp_link.c:226)[0;m [1;31m20241128090939728 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-43-ttcn3-bsc-client)[0x564915ffd770]{WAIT_DELETE_ACK}: Received Event CBSP_DELETE_ACK (cbsp_link_fsm.c:351)[0;m [1;31m20241128090939728 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-43-ttcn3-bsc-client)[0x564915ffd770]{WAIT_DELETE_ACK}: Appending CellId CGI 901-70-23-42 to Cell list (cbsp_smscb_peer_fsm.c:200)[0;m [1;31m20241128090939728 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-43-ttcn3-bsc-client)[0x564915ffd770]{WAIT_DELETE_ACK}: Appending CellId CGI 901-70-24-42 to Cell list (cbsp_smscb_peer_fsm.c:200)[0;m [1;31m20241128090939728 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-43-ttcn3-bsc-client)[0x564915ffd770]{WAIT_DELETE_ACK}: Appending CellId CGI 901-70-24-43 to Cell list (cbsp_smscb_peer_fsm.c:200)[0;m [1;31m20241128090939728 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-43-ttcn3-bsc-client)[0x564915ffd770]{WAIT_DELETE_ACK}: State change to DELETED (no timeout) (cbsp_smscb_peer_fsm.c:416)[0;m [1;35m20241128090939728 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-43)[0x564915ffd640]{WAIT_DELETE_ACK}: Received Event DELETE_ACK (cbsp_smscb_peer_fsm.c:418)[0;m [1;32m20241128090939730 [1;34mDSBcAP[0;m[1;32m [1;34mDEBUG[0;m[1;32m ttcn3-mme-client: sbcap_cbc_srv_read_cb(): sctp_recvmsg() returned 24 (flags=0x80) (sbcap_link.c:246)[0;m [1;32m20241128090939730 [1;34mDSBcAP[0;m[1;32m [1;34mDEBUG[0;m[1;32m ttcn3-mme-client: Rx SBc-AP 20 01 00 14 00 00 03 00 05 00 02 00 2b 00 0b 00 02 41 70 00 01 00 01 00 (sbcap_link.c:281)[0;m [1;32m20241128090939730 [1;34mDSBcAP[0;m[1;32m [1;34mDEBUG[0;m[1;32m Decoded Stop-Warning-Response (sbcap_common.c:118)[0;m [1;32m20241128090939730 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m ttcn3-mme-client: Rx SBc-AP Stop-Warning-Response (sbcap_link.c:286)[0;m [1;32m20241128090939730 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m ttcn3-mme-client: SBcAP SuccessfulOutcome procedure=1 (sbcap_link_fsm.c:318)[0;m [1;32m20241128090939730 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-43-ttcn3-mme-client)[0x564915fff0b0]{WAIT_DELETE_ACK}: Received Event SBcAP_DELETE_ACK (sbcap_link_fsm.c:379)[0;m [1;32m20241128090939730 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-43-ttcn3-mme-client)[0x564915fff0b0]{WAIT_DELETE_ACK}: State change to DELETED (no timeout) (sbcap_smscb_peer_fsm.c:209)[0;m [1;35m20241128090939730 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-43)[0x564915ffd640]{WAIT_DELETE_ACK}: Received Event DELETE_ACK (sbcap_smscb_peer_fsm.c:211)[0;m [1;33m20241128090939730 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m rest_it_op_complete(op=0x7f1ae0001460) complete (rest_it_op.c:131)[0;m [1;35m20241128090939730 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-43)[0x564915ffd640]{WAIT_DELETE_ACK}: State change to DELETED (no timeout) (smscb_message_fsm.c:206)[0;m [1;33m20241128090939730 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m rest_it_op completed with 0 (HTTP 200) (rest_it_op.c:70)[0;m [1;33m20241128090939730 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m /message DELETE(43) -> 200 (OK) (rest_api.c:635)[0;m MTC@1dc49bd4234e: setverdict(pass): pass -> pass, component reason not changed MTC@1dc49bd4234e: setverdict(pass): pass -> pass, component reason not changed [1;31m20241128090939735 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m ttcn3-bsc-client: read_cb rx_msg=(nil) (cbsp_link.c:203)[0;m [1;31m20241128090939735 [1;33mDCBSP[0;m[1;31m [1;33mNOTICE[0;m[1;31m ttcn3-bsc-client: connection closed (cbsp_link.c:240)[0;m [1;31m20241128090939735 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m CBSP-Link(ttcn3-bsc-client)[0x564915f9ea90]{IDLE}: Received Event CLOSE.cmd (cbsp_link.c:246)[0;m [1;31m20241128090939735 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m CBSP-Link(ttcn3-bsc-client)[0x564915f9ea90]{IDLE}: Terminating (cause = OSMO_FSM_TERM_REQUEST) (cbsp_link_fsm.c:170)[0;m [1;31m20241128090939735 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m CBSP-Link(ttcn3-bsc-client)[0x564915f9ea90]{IDLE}: Freeing instance (cbsp_link_fsm.c:170)[0;m [1;31m20241128090939735 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m CBSP-Link(ttcn3-bsc-client)[0x564915f9ea90]{IDLE}: Deallocated (fsm.c:568)[0;m TC_ecbe_create_delete_bsc_and_mme-BSC0(21)@1dc49bd4234e: Final verdict of PTC: none TC_ecbe_create_delete_bsc_and_mme-MME0(22)@1dc49bd4234e: Final verdict of PTC: none TC_ecbe_create_delete_bsc_and_mme-BSC0-BSC0(23)@1dc49bd4234e: Final verdict of PTC: none TC_ecbe_create_delete_bsc_and_mme-MME0-MME0(24)@1dc49bd4234e: Final verdict of PTC: none MTC@1dc49bd4234e: Setting final verdict of the test case. MTC@1dc49bd4234e: Local verdict of MTC: pass MTC@1dc49bd4234e: Local verdict of PTC TC_ecbe_create_delete_bsc_and_mme-BSC0(21): none (pass -> pass) MTC@1dc49bd4234e: Local verdict of PTC TC_ecbe_create_delete_bsc_and_mme-MME0(22): none (pass -> pass) MTC@1dc49bd4234e: Local verdict of PTC TC_ecbe_create_delete_bsc_and_mme-BSC0-BSC0(23): none (pass -> pass) MTC@1dc49bd4234e: Local verdict of PTC TC_ecbe_create_delete_bsc_and_mme-MME0-MME0(24): none (pass -> pass) MTC@1dc49bd4234e: Test case TC_ecbe_create_delete_bsc_and_mme finished. Verdict: pass MTC@1dc49bd4234e: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh CBC_Tests.TC_ecbe_create_delete_bsc_and_mme pass'. Thu Nov 28 09:09:39 UTC 2024 [1;32m====== CBC_Tests.TC_ecbe_create_delete_bsc_and_mme pass ======[0m
Saving talloc report from 127.0.0.20:4264 to CBC_Tests.TC_ecbe_create_delete_bsc_and_mme.talloc 20241128090939775 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m Accept()ed new telnet connection r=127.0.0.1:56802<->l=127.0.0.20:4264 (telnet_interface.c:192) 20241128090939775 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m Closing telnet connection r=127.0.0.1:56802<->l=127.0.0.20:4264 (telnet_interface.c:138) Waiting for packet dumper to finish... 0 (prev_count=-1, count=35772) [1;32m20241128090939930 [1;34mDSBcAP[0;m[1;32m [1;34mDEBUG[0;m[1;32m ttcn3-mme-client: sbcap_cbc_srv_read_cb(): sctp_recvmsg() returned 12 (flags=0x8080) (sbcap_link.c:246)[0;m [1;32m20241128090939930 [1;34mDSBcAP[0;m[1;32m [1;34mDEBUG[0;m[1;32m ttcn3-mme-client: Rx sctp notif SHUTDOWN_EVENT (sbcap_link.c:259)[0;m [1;32m20241128090939930 [1;33mDSBcAP[0;m[1;32m [1;33mNOTICE[0;m[1;32m ttcn3-mme-client: connection closed (sbcap_link.c:301)[0;m [1;32m20241128090939930 [1;34mDSBcAP[0;m[1;32m [1;34mDEBUG[0;m[1;32m SBcAP-Link(ttcn3-mme-client)[0x564915ffd3b0]{IDLE}: Received Event CLOSE.cmd (sbcap_link.c:307)[0;m [1;32m20241128090939930 [1;34mDSBcAP[0;m[1;32m [1;34mDEBUG[0;m[1;32m SBcAP-Link(ttcn3-mme-client)[0x564915ffd3b0]{IDLE}: Terminating (cause = OSMO_FSM_TERM_REQUEST) (sbcap_link_fsm.c:78)[0;m [1;32m20241128090939930 [1;34mDSBcAP[0;m[1;32m [1;34mDEBUG[0;m[1;32m SBcAP-Link(ttcn3-mme-client)[0x564915ffd3b0]{IDLE}: Freeing instance (sbcap_link_fsm.c:78)[0;m [1;32m20241128090939930 [1;34mDSBcAP[0;m[1;32m [1;34mDEBUG[0;m[1;32m SBcAP-Link(ttcn3-mme-client)[0x564915ffd3b0]{IDLE}: Deallocated (fsm.c:568)[0;m Waiting for packet dumper to finish... 1 (prev_count=35772, count=57952) MTC@1dc49bd4234e: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh CBC_Tests.TC_ecbe_create_delete_bsc_and_mme pass' was executed successfully (exit status: 0). MTC@1dc49bd4234e: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh CBC_Tests.TC_ecbe_create_delete_bsc_server'. ------ CBC_Tests.TC_ecbe_create_delete_bsc_server ------ Thu Nov 28 09:09:41 UTC 2024 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test/1389/artifact/logs/testsuite/CBC_Tests.TC_ecbe_create_delete_bsc_server.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test/1389/artifact/logs/testsuite/CBC_Tests.TC_ecbe_create_delete_bsc_server.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 MTC@1dc49bd4234e: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh CBC_Tests.TC_ecbe_create_delete_bsc_server' was executed successfully (exit status: 0). MTC@1dc49bd4234e: Test case TC_ecbe_create_delete_bsc_server started. MTC@1dc49bd4234e: Abstract socket: warning: HTTP: to switch on HTTP test port debugging, set the '*.HTTP.http_debugging := "yes" in the port's parameters. [38;5;23m20241128090943628 [1;31mDLINP[0;m[38;5;23m [1;31mERROR[0;m[38;5;23m CLICONN(,){CONNECTING} connect so_error (111) (stream_cli.c:423)[0;m [38;5;23m20241128090943628 [1;32mDLINP[0;m[38;5;23m [1;32mINFO[0;m[38;5;23m CLICONN(,){WAIT_RECONNECT} retrying reconnect in 5 seconds... (stream_cli.c:239)[0;m [38;5;23m20241128090943628 [1;32mDLINP[0;m[38;5;23m [1;32mINFO[0;m[38;5;23m CLICONN(,r=127.0.0.100:15001<->l=127.0.0.20:38469){CONNECTING} connection established (stream_cli.c:436)[0;m [1;31m20241128090943628 [1;33mDCBSP[0;m[1;31m [1;33mNOTICE[0;m[1;31m ttcn3-bsc-server: Connected (cbsp_link.c:97)[0;m [1;31m20241128090943628 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m CBSP-Link(ttcn3-bsc-server)[0x564915fbcd00]{INIT}: Received Event RESET.cmd (cbsp_link.c:98)[0;m [1;31m20241128090943628 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m CBSP-Link(ttcn3-bsc-server)[0x564915fbcd00]{INIT}: State change to RESET_PENDING (no timeout) (cbsp_link_fsm.c:68)[0;m [1;31m20241128090943628 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m ttcn3-bsc-server: Transmitting RESET (cbsp_link.c:341)[0;m [1;31m20241128090943628 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m CBSP-Link(ttcn3-bsc-server)[0x564915fbcd00]{RESET_PENDING}: State change to RESET_PENDING (T3, 5s) (cbsp_link_fsm.c:91)[0;m TC_ecbe_create_delete_bsc_server-BSC0-BSC0(27)@1dc49bd4234e: Connection from "127.0.0.20":38469 [1;31m20241128090943635 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m ttcn3-bsc-server: read_cb rx_msg=(nil) (cbsp_link.c:119)[0;m [1;31m20241128090943635 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m ttcn3-bsc-server: Received CBSP [L1]> 13 00 00 08 [L2]> 04 00 01 06 16 00 0d 01 (cbsp_link.c:137)[0;m [1;31m20241128090943635 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m ttcn3-bsc-server: Received CBSP RESTART (cbsp_link.c:141)[0;m [1;31m20241128090943635 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m CBSP-Link(ttcn3-bsc-server)[0x564915fbcd00]{RESET_PENDING}: Received Event Rx Restart (cbsp_link_fsm.c:284)[0;m [1;31m20241128090943635 [1;33mDCBSP[0;m[1;31m [1;33mNOTICE[0;m[1;31m ttcn3-bsc-server: RESTART (CBS) but re-sending not implemented yet (cbsp_link_fsm.c:181)[0;m [1;31m20241128090943636 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m ttcn3-bsc-server: read_cb rx_msg=(nil) (cbsp_link.c:119)[0;m [1;31m20241128090943636 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m ttcn3-bsc-server: Received CBSP [L1]> 13 00 00 08 [L2]> 04 00 01 06 16 01 0d 01 (cbsp_link.c:137)[0;m [1;31m20241128090943636 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m ttcn3-bsc-server: Received CBSP RESTART (cbsp_link.c:141)[0;m [1;31m20241128090943636 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m CBSP-Link(ttcn3-bsc-server)[0x564915fbcd00]{RESET_PENDING}: Received Event Rx Restart (cbsp_link_fsm.c:284)[0;m [1;31m20241128090943636 [1;33mDCBSP[0;m[1;31m [1;33mNOTICE[0;m[1;31m ttcn3-bsc-server: RESTART (ETWS) but re-sending not implemented yet (cbsp_link_fsm.c:186)[0;m [1;31m20241128090943638 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m ttcn3-bsc-server: read_cb rx_msg=(nil) (cbsp_link.c:119)[0;m [1;31m20241128090943638 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m ttcn3-bsc-server: Received CBSP [L1]> 11 00 00 04 [L2]> 04 00 01 06 (cbsp_link.c:137)[0;m [1;31m20241128090943638 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m ttcn3-bsc-server: Received CBSP RESET COMPLETE (cbsp_link.c:141)[0;m [1;31m20241128090943638 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m CBSP-Link(ttcn3-bsc-server)[0x564915fbcd00]{RESET_PENDING}: Received Event Rx Reset Complete (cbsp_link_fsm.c:301)[0;m [1;31m20241128090943638 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m CBSP-Link(ttcn3-bsc-server)[0x564915fbcd00]{RESET_PENDING}: State change to IDLE (no timeout) (cbsp_link_fsm.c:99)[0;m MTC@1dc49bd4234e: TX POST CBS: "{"cbe_name":"TTCN-3","category":"normal","repetition_period":5,"num_of_bcast":3,"scope":{"scope_plmn":{}},"smscb_message":{"serial_nr":{"serial_nr_encoded":16752},"message_id":46,"payload":{"payload_encoded":{"dcs":1,"pages":["00"]}}}}" [1;33m20241128090943641 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m /message POST: {"cbe_name": "TTCN-3", "category": "normal", "repetition_period": 5, "num_of_bcast": 3, "scope": {"scope_plmn": {}}, "smscb_message": {"serial_nr": {"serial_nr_encoded": 16752}, "message_id": 46, "payload": {"payload_encoded": {"dcs": 1, "pages": ["00"]}}}} (rest_api.c:571)[0;m [1;33m20241128090943641 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m sending as inter-thread op (rest_api.c:578)[0;m [1;33m20241128090943641 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m rest_it_op enqueue from 139753614202560 (rest_it_op.c:57)[0;m [1;33m20241128090943641 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m rest_it_op wait.... (rest_it_op.c:66)[0;m [1;33m20241128090943641 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m rest2main_read_cb(op=0x7f1ae0001510) from 139753629112896 (rest_it_op.c:93)[0;m [1;35m20241128090943641 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-46)[0x564915ffd3b0]{INIT}: Allocated (fsm.c:456)[0;m [1;31m20241128090943641 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46)[0x564915f9ea90]{INIT}: Allocated (fsm.c:456)[0;m [1;31m20241128090943641 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46)[0x564915f9ea90]{INIT}: is child of SMSCB(TTCN-3-46)[0x564915ffd3b0] (fsm.c:486)[0;m [1;31m20241128090943641 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46)[0x564916000c50]{INIT}: Allocated (fsm.c:456)[0;m [1;31m20241128090943641 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46)[0x564916000c50]{INIT}: is child of SMSCB(TTCN-3-46)[0x564915ffd3b0] (fsm.c:486)[0;m [1;32m20241128090943641 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-46)[0x564916000e30]{INIT}: Allocated (fsm.c:456)[0;m [1;32m20241128090943641 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-46)[0x564916000e30]{INIT}: is child of SMSCB(TTCN-3-46)[0x564915ffd3b0] (fsm.c:486)[0;m [1;32m20241128090943641 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-46)[0x564916001850]{INIT}: Allocated (fsm.c:456)[0;m [1;32m20241128090943641 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-46)[0x564916001850]{INIT}: is child of SMSCB(TTCN-3-46)[0x564915ffd3b0] (fsm.c:486)[0;m [1;35m20241128090943641 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-46)[0x564915ffd3b0]{INIT}: Received Event CREATE (cbc_message.c:132)[0;m [1;35m20241128090943641 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-46)[0x564915ffd3b0]{INIT}: State change to WAIT_WRITE_ACK (T0, 15s) (smscb_message_fsm.c:67)[0;m [1;32m20241128090943641 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-server)[0x564916001850]{INIT}: Received Event CREATE (smscb_message_fsm.c:69)[0;m [1;32m20241128090943641 [1;33mDSBcAP[0;m[1;32m [1;33mNOTICE[0;m[1;32m ttcn3-mme-server: Cannot transmit msg Write-Replace-Warning-Request: reconnecting (sbcap_link.c:402)[0;m [1;32m20241128090943641 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-server)[0x564916001850]{INIT}: State change to WAIT_WRITE_ACK (T0, 10s) (sbcap_smscb_peer_fsm.c:119)[0;m [1;32m20241128090943641 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-server)[0x564916001850]{WAIT_WRITE_ACK}: State change to ACTIVE (no timeout) (sbcap_smscb_peer_fsm.c:230)[0;m [1;35m20241128090943641 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-46)[0x564915ffd3b0]{WAIT_WRITE_ACK}: Received Event WRITE_NACK (sbcap_smscb_peer_fsm.c:231)[0;m [1;32m20241128090943641 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-client)[0x564916000e30]{INIT}: Received Event CREATE (smscb_message_fsm.c:69)[0;m [1;32m20241128090943641 [1;33mDSBcAP[0;m[1;32m [1;33mNOTICE[0;m[1;32m [ttcn3-mme-client] Tx SBc-AP: not connected (cbc_message.c:78)[0;m [1;32m20241128090943642 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-client)[0x564916000e30]{INIT}: State change to WAIT_WRITE_ACK (T0, 10s) (sbcap_smscb_peer_fsm.c:119)[0;m [1;32m20241128090943642 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-client)[0x564916000e30]{WAIT_WRITE_ACK}: State change to ACTIVE (no timeout) (sbcap_smscb_peer_fsm.c:230)[0;m [1;35m20241128090943642 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-46)[0x564915ffd3b0]{WAIT_WRITE_ACK}: Received Event WRITE_NACK (sbcap_smscb_peer_fsm.c:231)[0;m [1;31m20241128090943642 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x564916000c50]{INIT}: Received Event CREATE (smscb_message_fsm.c:69)[0;m [1;31m20241128090943642 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m ttcn3-bsc-server: Transmitting WRITE-REPLACE (cbsp_link.c:341)[0;m [1;31m20241128090943642 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x564916000c50]{INIT}: State change to WAIT_WRITE_ACK (T0, 10s) (cbsp_smscb_peer_fsm.c:275)[0;m [1;31m20241128090943642 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-client)[0x564915f9ea90]{INIT}: Received Event CREATE (smscb_message_fsm.c:69)[0;m [1;31m20241128090943642 [1;33mDCBSP[0;m[1;31m [1;33mNOTICE[0;m[1;31m [ttcn3-bsc-client] Tx CBSP: not connected (cbc_message.c:64)[0;m [1;31m20241128090943642 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-client)[0x564915f9ea90]{INIT}: State change to WAIT_WRITE_ACK (T0, 10s) (cbsp_smscb_peer_fsm.c:275)[0;m [1;31m20241128090943642 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-client)[0x564915f9ea90]{WAIT_WRITE_ACK}: State change to ACTIVE (no timeout) (cbsp_smscb_peer_fsm.c:439)[0;m [1;35m20241128090943642 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-46)[0x564915ffd3b0]{WAIT_WRITE_ACK}: Received Event WRITE_ACK (cbsp_smscb_peer_fsm.c:440)[0;m [1;31m20241128090943644 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m ttcn3-bsc-server: read_cb rx_msg=(nil) (cbsp_link.c:119)[0;m [1;31m20241128090943644 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m ttcn3-bsc-server: Received CBSP [L1]> 02 00 00 12 [L2]> 0e 00 2e 03 41 70 04 00 07 02 c3 51 c3 52 c3 53 12 00 (cbsp_link.c:137)[0;m [1;31m20241128090943644 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m ttcn3-bsc-server: Received CBSP WRITE-REPLACE COMPLETE (cbsp_link.c:141)[0;m [1;31m20241128090943644 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x564916000c50]{WAIT_WRITE_ACK}: Received Event CBSP_WRITE_ACK (cbsp_link_fsm.c:344)[0;m [1;31m20241128090943644 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x564916000c50]{WAIT_WRITE_ACK}: Appending CellId CI 50001 to Cell list (cbsp_smscb_peer_fsm.c:200)[0;m [1;31m20241128090943644 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x564916000c50]{WAIT_WRITE_ACK}: Appending CellId CI 50002 to Cell list (cbsp_smscb_peer_fsm.c:200)[0;m [1;31m20241128090943644 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x564916000c50]{WAIT_WRITE_ACK}: Appending CellId CI 50003 to Cell list (cbsp_smscb_peer_fsm.c:200)[0;m [1;31m20241128090943644 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x564916000c50]{WAIT_WRITE_ACK}: State change to ACTIVE (no timeout) (cbsp_smscb_peer_fsm.c:294)[0;m [1;35m20241128090943644 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-46)[0x564915ffd3b0]{WAIT_WRITE_ACK}: Received Event WRITE_ACK (cbsp_smscb_peer_fsm.c:296)[0;m [1;33m20241128090943644 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m rest_it_op_complete(op=0x7f1ae0001510) complete (rest_it_op.c:131)[0;m [1;35m20241128090943644 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-46)[0x564915ffd3b0]{WAIT_WRITE_ACK}: State change to ACTIVE (no timeout) (smscb_message_fsm.c:91)[0;m [1;33m20241128090943644 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m rest_it_op completed with 0 (HTTP 201) (rest_it_op.c:70)[0;m [1;33m20241128090943644 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m /message POST -> 201 (Created) (rest_api.c:588)[0;m MTC@1dc49bd4234e: setverdict(pass): none -> pass [1;33m20241128090945648 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m rest_it_op enqueue from 139753614202560 (rest_it_op.c:57)[0;m [1;33m20241128090945648 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m rest2main_read_cb(op=0x7f1ae0001510) from 139753629112896 (rest_it_op.c:93)[0;m [1;35m20241128090945648 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-46)[0x564915ffd3b0]{ACTIVE}: Received Event DELETE (cbc_message.c:144)[0;m [1;35m20241128090945648 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-46)[0x564915ffd3b0]{ACTIVE}: State change to WAIT_DELETE_ACK (T3, 15s) (smscb_message_fsm.c:128)[0;m [1;32m20241128090945648 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-server)[0x564916001850]{ACTIVE}: Received Event DELETE (smscb_message_fsm.c:130)[0;m [1;32m20241128090945648 [1;33mDSBcAP[0;m[1;32m [1;33mNOTICE[0;m[1;32m ttcn3-mme-server: Cannot transmit msg Stop-Warning-Request: reconnecting (sbcap_link.c:402)[0;m [1;32m20241128090945648 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-server)[0x564916001850]{ACTIVE}: State change to WAIT_DELETE_ACK (T3, 10s) (sbcap_smscb_peer_fsm.c:278)[0;m [1;32m20241128090945648 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-server)[0x564916001850]{WAIT_DELETE_ACK}: State change to DELETED (no timeout) (sbcap_smscb_peer_fsm.c:242)[0;m [1;35m20241128090945648 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-46)[0x564915ffd3b0]{WAIT_DELETE_ACK}: Received Event DELETE_NACK (sbcap_smscb_peer_fsm.c:243)[0;m [1;32m20241128090945648 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-client)[0x564916000e30]{ACTIVE}: Received Event DELETE (smscb_message_fsm.c:130)[0;m [1;32m20241128090945648 [1;33mDSBcAP[0;m[1;32m [1;33mNOTICE[0;m[1;32m Cannot transmit msg Stop-Warning-Request: no connection (sbcap_link.c:397)[0;m [1;32m20241128090945648 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-client)[0x564916000e30]{ACTIVE}: State change to WAIT_DELETE_ACK (T3, 10s) (sbcap_smscb_peer_fsm.c:278)[0;m [1;32m20241128090945648 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-client)[0x564916000e30]{WAIT_DELETE_ACK}: State change to DELETED (no timeout) (sbcap_smscb_peer_fsm.c:242)[0;m [1;35m20241128090945648 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-46)[0x564915ffd3b0]{WAIT_DELETE_ACK}: Received Event DELETE_NACK (sbcap_smscb_peer_fsm.c:243)[0;m [1;31m20241128090945648 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x564916000c50]{ACTIVE}: Received Event DELETE (smscb_message_fsm.c:130)[0;m [1;31m20241128090945648 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m ttcn3-bsc-server: Transmitting KILL (cbsp_link.c:341)[0;m [1;31m20241128090945648 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x564916000c50]{ACTIVE}: State change to WAIT_DELETE_ACK (T3, 10s) (cbsp_smscb_peer_fsm.c:490)[0;m [1;31m20241128090945648 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-client)[0x564915f9ea90]{ACTIVE}: Received Event DELETE (smscb_message_fsm.c:130)[0;m [1;31m20241128090945648 [1;33mDCBSP[0;m[1;31m [1;33mNOTICE[0;m[1;31m Cannot transmit KILL: no connection (cbsp_link.c:330)[0;m [1;31m20241128090945648 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-client)[0x564915f9ea90]{ACTIVE}: State change to WAIT_DELETE_ACK (T3, 10s) (cbsp_smscb_peer_fsm.c:490)[0;m [1;31m20241128090945648 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-client)[0x564915f9ea90]{WAIT_DELETE_ACK}: State change to DELETED (no timeout) (cbsp_smscb_peer_fsm.c:451)[0;m [1;35m20241128090945648 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-46)[0x564915ffd3b0]{WAIT_DELETE_ACK}: Received Event DELETE_ACK (cbsp_smscb_peer_fsm.c:452)[0;m [1;33m20241128090945649 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m rest_it_op wait.... (rest_it_op.c:66)[0;m [1;31m20241128090945650 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m ttcn3-bsc-server: read_cb rx_msg=(nil) (cbsp_link.c:119)[0;m [1;31m20241128090945650 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m ttcn3-bsc-server: Received CBSP [L1]> 05 00 00 12 [L2]> 0e 00 2e 02 41 70 04 00 07 02 c3 51 c3 52 c3 53 12 00 (cbsp_link.c:137)[0;m [1;31m20241128090945650 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m ttcn3-bsc-server: Received CBSP KILL COMPLETE (cbsp_link.c:141)[0;m [1;31m20241128090945650 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x564916000c50]{WAIT_DELETE_ACK}: Received Event CBSP_DELETE_ACK (cbsp_link_fsm.c:351)[0;m [1;31m20241128090945650 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x564916000c50]{WAIT_DELETE_ACK}: Appending CellId CI 50001 to Cell list (cbsp_smscb_peer_fsm.c:200)[0;m [1;31m20241128090945650 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x564916000c50]{WAIT_DELETE_ACK}: Appending CellId CI 50002 to Cell list (cbsp_smscb_peer_fsm.c:200)[0;m [1;31m20241128090945650 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x564916000c50]{WAIT_DELETE_ACK}: Appending CellId CI 50003 to Cell list (cbsp_smscb_peer_fsm.c:200)[0;m [1;31m20241128090945650 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x564916000c50]{WAIT_DELETE_ACK}: State change to DELETED (no timeout) (cbsp_smscb_peer_fsm.c:416)[0;m [1;35m20241128090945650 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-46)[0x564915ffd3b0]{WAIT_DELETE_ACK}: Received Event DELETE_ACK (cbsp_smscb_peer_fsm.c:418)[0;m [1;33m20241128090945650 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m rest_it_op_complete(op=0x7f1ae0001510) complete (rest_it_op.c:131)[0;m [1;35m20241128090945650 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m SMSCB(TTCN-3-46)[0x564915ffd3b0]{WAIT_DELETE_ACK}: State change to DELETED (no timeout) (smscb_message_fsm.c:206)[0;m [1;33m20241128090945651 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m rest_it_op completed with 0 (HTTP 200) (rest_it_op.c:70)[0;m [1;33m20241128090945651 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m /message DELETE(46) -> 200 (OK) (rest_api.c:635)[0;m MTC@1dc49bd4234e: setverdict(pass): pass -> pass, component reason not changed MTC@1dc49bd4234e: setverdict(pass): pass -> pass, component reason not changed TC_ecbe_create_delete_bsc_server-BSC1(26)@1dc49bd4234e: Final verdict of PTC: none TC_ecbe_create_delete_bsc_server-BSC0(25)@1dc49bd4234e: Final verdict of PTC: none [1;31m20241128090945655 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m ttcn3-bsc-server: read_cb rx_msg=(nil) (cbsp_link.c:119)[0;m [1;31m20241128090945655 [1;33mDCBSP[0;m[1;31m [1;33mNOTICE[0;m[1;31m ttcn3-bsc-server: Disconnected. (cbsp_link.c:105)[0;m [1;31m20241128090945655 [1;33mDCBSP[0;m[1;31m [1;33mNOTICE[0;m[1;31m ttcn3-bsc-server: Reconnecting... (cbsp_link.c:106)[0;m [38;5;23m20241128090945655 [1;32mDLINP[0;m[38;5;23m [1;32mINFO[0;m[38;5;23m CLICONN(,r=127.0.0.100:15001<->l=127.0.0.20:38469){WAIT_RECONNECT} retrying reconnect in 5 seconds... (stream_cli.c:239)[0;m [1;31m20241128090945655 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m CBSP-Link(ttcn3-bsc-server)[0x564915fbcd00]{IDLE}: Received Event CLOSE.cmd (cbsp_link.c:370)[0;m [1;31m20241128090945655 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m CBSP-Link(ttcn3-bsc-server)[0x564915fbcd00]{IDLE}: Terminating (cause = OSMO_FSM_TERM_REQUEST) (cbsp_link_fsm.c:170)[0;m [1;31m20241128090945656 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m CBSP-Link(ttcn3-bsc-server)[0x564915fbcd00]{IDLE}: Freeing instance (cbsp_link_fsm.c:170)[0;m [1;31m20241128090945656 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m CBSP-Link(ttcn3-bsc-server)[0x564915fbcd00]{IDLE}: Deallocated (fsm.c:568)[0;m TC_ecbe_create_delete_bsc_server-BSC0-BSC0(27)@1dc49bd4234e: Final verdict of PTC: none MTC@1dc49bd4234e: Setting final verdict of the test case. MTC@1dc49bd4234e: Local verdict of MTC: pass MTC@1dc49bd4234e: Local verdict of PTC TC_ecbe_create_delete_bsc_server-BSC0(25): none (pass -> pass) MTC@1dc49bd4234e: Local verdict of PTC TC_ecbe_create_delete_bsc_server-BSC1(26): none (pass -> pass) Aborted MTC@1dc49bd4234e: Local verdict of PTC TC_ecbe_create_delete_bsc_server-BSC0-BSC0(27): none (pass -> pass) MTC@1dc49bd4234e: Test case TC_ecbe_create_delete_bsc_server finished. Verdict: pass MTC@1dc49bd4234e: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh CBC_Tests.TC_ecbe_create_delete_bsc_server pass'. Thu Nov 28 09:09:45 UTC 2024 [1;32m====== CBC_Tests.TC_ecbe_create_delete_bsc_server pass ======[0m
Saving talloc report from 127.0.0.20:4264 to CBC_Tests.TC_ecbe_create_delete_bsc_server.talloc [1;34m[testenv] Looking for a coredump[0m [0;94m[testenv] coredumpctl is not available, won't try to get coredump[0m [1;91m[testenv] cbc crashed during CBC_Tests.TC_ecbe_create_delete_bsc_server![0m [0;94m[testenv] Waiting until test has stopped...[0m Traceback (most recent call last): File "/usr/local/lib/python3.11/dist-packages/osmopy/osmo_interact/common.py", line 420, in main_run_commands interact.connect() File "/usr/local/lib/python3.11/dist-packages/osmopy/osmo_interact/vty.py", line 84, in connect super().connect() File "/usr/local/lib/python3.11/dist-packages/osmopy/osmo_interact/common.py", line 88, in connect self.socket.connect((self.host, int(self.port))) ConnectionRefusedError: [Errno 111] Connection refused Waiting for packet dumper to finish... 0 (prev_count=-1, count=46632) Waiting for packet dumper to finish... 1 (prev_count=46632, count=47808) MTC@1dc49bd4234e: External command `https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh CBC_Tests.TC_ecbe_create_delete_bsc_server pass' was executed successfully (exit status: 0). MTC@1dc49bd4234e: Starting external command `https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-start.sh CBC_Tests.TC_ecbe_create_delete_mme_server'. ------ CBC_Tests.TC_ecbe_create_delete_mme_server ------ Thu Nov 28 09:09:50 UTC 2024 /usr/bin/dumpcap -q -s 1520 -n -i any -w "https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test/1389/artifact/logs/testsuite/CBC_Tests.TC_ecbe_create_delete_mme_server.pcap" >https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test/1389/artifact/logs/testsuite/CBC_Tests.TC_ecbe_create_delete_mme_server.pcap.stdout 2>/tmp/cmderr & Waiting for packet dumper to start... 0 [1;34m[testenv] Stopping podman container[0m [0;94m[testenv] + ['podman', 'kill', 'testenv-cbc-osmocom-nightly-20241128-0907-041fd560-0'][0m testenv-cbc-osmocom-nightly-20241128-0907-041fd560-0 [1;34m[testenv] Stopping testsuite (3932925)[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-cbc-test/1389/artifact/logs/ [0m Build step 'Execute shell' marked build as failure Recording test results [Checks API] No suitable checks publisher found.
Tracked here: https://osmocom.org/issues/6651 Fixed here: https://gerrit.osmocom.org/c/libosmo-netif/+/38975/
jenkins-notifications@lists.osmocom.org
-
jenkins＠lists.osmocom.org -
Pau Espin Pedrol