Build failed in Jenkins: ttcn3-cbc-test #1389

28 Nov 2024

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.

2025

2024

2023

2022

2021

2020

2019

Build failed in Jenkins: ttcn3-cbc-test #1389