Build failed in Jenkins: ttcn3-cbc-test-asan #173 - jenkins-notifications

28 Nov 2024

See
<https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test-asan/173/display/redirect?page=changes>

Changes:

[Pau Espin Pedrol] bsc: osmo-bsc.cfg: Listen IPA Abis and CTRL interfaces on 127.0.0.1


------------------------------------------
[...truncated 511.98 KiB...]
TC_ecbe_create_delete_bsc_and_mme-MME0-MME0(24)@719ebcad609d: Final verdict of PTC: none
TC_ecbe_create_delete_bsc_and_mme-BSC0-BSC0(23)@719ebcad609d: Final verdict of PTC: none
MTC@719ebcad609d: Setting final verdict of the test case.
MTC@719ebcad609d: Local verdict of MTC: pass
MTC@719ebcad609d: Local verdict of PTC TC_ecbe_create_delete_bsc_and_mme-BSC0(21): none
(pass -> pass)
MTC@719ebcad609d: Local verdict of PTC TC_ecbe_create_delete_bsc_and_mme-MME0(22): none
(pass -> pass)
MTC@719ebcad609d: Local verdict of PTC TC_ecbe_create_delete_bsc_and_mme-BSC0-BSC0(23):
none (pass -> pass)
MTC@719ebcad609d: Local verdict of PTC TC_ecbe_create_delete_bsc_and_mme-MME0-MME0(24):
none (pass -> pass)
MTC@719ebcad609d: Test case TC_ecbe_create_delete_bsc_and_mme finished. Verdict: pass
MTC@719ebcad609d: Starting external command
`<https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test-asan/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh>
CBC_Tests.TC_ecbe_create_delete_bsc_and_mme pass'.
Thu Nov 28 16:49:47 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
20241128164947650 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m Accept()ed new telnet connection
r=127.0.0.1:49330<->l=127.0.0.20:4264 (telnet_interface.c:192)
20241128164947651 [1;32mDLGLOBAL[0;m [1;32mINFO[0;m Closing telnet connection
r=127.0.0.1:49330<->l=127.0.0.20:4264 (telnet_interface.c:138)
Waiting for packet dumper to finish... 0 (prev_count=-1, count=35768)
[1;32m20241128164947813 [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;32m20241128164947813 [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;32m20241128164947813 [1;33mDSBcAP[0;m[1;32m [1;33mNOTICE[0;m[1;32m
ttcn3-mme-client: connection closed (sbcap_link.c:301)[0;m
[1;32m20241128164947814 [1;34mDSBcAP[0;m[1;32m [1;34mDEBUG[0;m[1;32m
SBcAP-Link(ttcn3-mme-client)[0x6120000078a0]{IDLE}: Received Event CLOSE.cmd
(sbcap_link.c:307)[0;m
[1;32m20241128164947814 [1;34mDSBcAP[0;m[1;32m [1;34mDEBUG[0;m[1;32m
SBcAP-Link(ttcn3-mme-client)[0x6120000078a0]{IDLE}: Terminating (cause =
OSMO_FSM_TERM_REQUEST) (sbcap_link_fsm.c:78)[0;m
[1;32m20241128164947814 [1;34mDSBcAP[0;m[1;32m [1;34mDEBUG[0;m[1;32m
SBcAP-Link(ttcn3-mme-client)[0x6120000078a0]{IDLE}: Freeing instance
(sbcap_link_fsm.c:78)[0;m
[1;32m20241128164947814 [1;34mDSBcAP[0;m[1;32m [1;34mDEBUG[0;m[1;32m
SBcAP-Link(ttcn3-mme-client)[0x6120000078a0]{IDLE}: Deallocated (fsm.c:568)[0;m
Waiting for packet dumper to finish... 1 (prev_count=35768, count=57948)
MTC@719ebcad609d: External command
`<https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test-asan/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@719ebcad609d: Starting external command
`<https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test-asan/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 16:49:49 UTC 2024
/usr/bin/dumpcap -q -s 1520 -n -i any -w
"<https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test-asan/173/artifact/logs/testsuite/CBC_Tests.TC_ecbe_create_delete_bsc_server.pcap">
><https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test-asan/173/artifact/logs/testsuite/CBC_Tests.TC_ecbe_create_delete_bsc_server.pcap.stdout>
2>/tmp/cmderr &
Waiting for packet dumper to start... 0
MTC@719ebcad609d: External command
`<https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test-asan/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@719ebcad609d: Test case TC_ecbe_create_delete_bsc_server started.
MTC@719ebcad609d: Abstract socket: warning: HTTP: to switch on HTTP test port debugging,
set the '*.HTTP.http_debugging := "yes" in the port's parameters.
[38;5;23m20241128164951660 [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;23m20241128164951660 [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;23m20241128164951660 [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:43391){CONNECTING} connection
established (stream_cli.c:436)[0;m
[1;31m20241128164951660 [1;33mDCBSP[0;m[1;31m [1;33mNOTICE[0;m[1;31m
ttcn3-bsc-server: Connected (cbsp_link.c:97)[0;m
[1;31m20241128164951660 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m
CBSP-Link(ttcn3-bsc-server)[0x612000003220]{INIT}: Received Event RESET.cmd
(cbsp_link.c:98)[0;m
[1;31m20241128164951660 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m
CBSP-Link(ttcn3-bsc-server)[0x612000003220]{INIT}: State change to RESET_PENDING (no
timeout) (cbsp_link_fsm.c:68)[0;m
[1;31m20241128164951660 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
ttcn3-bsc-server: Transmitting RESET (cbsp_link.c:341)[0;m
[1;31m20241128164951661 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m
CBSP-Link(ttcn3-bsc-server)[0x612000003220]{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)@719ebcad609d: Connection from
"127.0.0.20":43391
[1;31m20241128164951663 [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;31m20241128164951663 [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;31m20241128164951663 [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;31m20241128164951663 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m
CBSP-Link(ttcn3-bsc-server)[0x612000003220]{RESET_PENDING}: Received Event Rx Restart
(cbsp_link_fsm.c:284)[0;m
[1;31m20241128164951663 [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;31m20241128164951663 [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;31m20241128164951663 [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;31m20241128164951663 [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;31m20241128164951663 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m
CBSP-Link(ttcn3-bsc-server)[0x612000003220]{RESET_PENDING}: Received Event Rx Restart
(cbsp_link_fsm.c:284)[0;m
[1;31m20241128164951663 [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;31m20241128164951665 [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;31m20241128164951665 [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;31m20241128164951665 [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;31m20241128164951665 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m
CBSP-Link(ttcn3-bsc-server)[0x612000003220]{RESET_PENDING}: Received Event Rx Reset
Complete (cbsp_link_fsm.c:301)[0;m
[1;31m20241128164951665 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m
CBSP-Link(ttcn3-bsc-server)[0x612000003220]{RESET_PENDING}: State change to IDLE (no
timeout) (cbsp_link_fsm.c:99)[0;m
MTC@719ebcad609d: 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;33m20241128164951666 [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;33m20241128164951666 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m sending as
inter-thread op (rest_api.c:578)[0;m
[1;33m20241128164951666 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m rest_it_op
enqueue from 140016481199808 (rest_it_op.c:57)[0;m
[1;33m20241128164951666 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m rest_it_op
wait.... (rest_it_op.c:66)[0;m
[1;33m20241128164951666 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m
rest2main_read_cb(op=0x61b0000261e0) from 140016523786944 (rest_it_op.c:93)[0;m
[1;35m20241128164951666 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m
SMSCB(TTCN-3-46)[0x6120000081a0]{INIT}: Allocated (fsm.c:456)[0;m
[1;31m20241128164951666 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46)[0x612000008320]{INIT}: Allocated (fsm.c:456)[0;m
[1;31m20241128164951666 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46)[0x612000008320]{INIT}: is child of
SMSCB(TTCN-3-46)[0x6120000081a0] (fsm.c:486)[0;m
[1;31m20241128164951666 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46)[0x6120000084a0]{INIT}: Allocated (fsm.c:456)[0;m
[1;31m20241128164951666 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46)[0x6120000084a0]{INIT}: is child of
SMSCB(TTCN-3-46)[0x6120000081a0] (fsm.c:486)[0;m
[1;32m20241128164951666 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m
SMSCB-PEER-SBcAP(TTCN-3-46)[0x612000008620]{INIT}: Allocated (fsm.c:456)[0;m
[1;32m20241128164951666 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m
SMSCB-PEER-SBcAP(TTCN-3-46)[0x612000008620]{INIT}: is child of
SMSCB(TTCN-3-46)[0x6120000081a0] (fsm.c:486)[0;m
[1;32m20241128164951666 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m
SMSCB-PEER-SBcAP(TTCN-3-46)[0x6120000087a0]{INIT}: Allocated (fsm.c:456)[0;m
[1;32m20241128164951666 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m
SMSCB-PEER-SBcAP(TTCN-3-46)[0x6120000087a0]{INIT}: is child of
SMSCB(TTCN-3-46)[0x6120000081a0] (fsm.c:486)[0;m
[1;35m20241128164951667 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m
SMSCB(TTCN-3-46)[0x6120000081a0]{INIT}: Received Event CREATE (cbc_message.c:132)[0;m
[1;35m20241128164951667 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m
SMSCB(TTCN-3-46)[0x6120000081a0]{INIT}: State change to WAIT_WRITE_ACK (T0, 15s)
(smscb_message_fsm.c:67)[0;m
[1;32m20241128164951667 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m
SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-server)[0x6120000087a0]{INIT}: Received Event CREATE
(smscb_message_fsm.c:69)[0;m
[1;32m20241128164951667 [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;32m20241128164951667 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m
SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-server)[0x6120000087a0]{INIT}: State change to
WAIT_WRITE_ACK (T0, 10s) (sbcap_smscb_peer_fsm.c:119)[0;m
[1;32m20241128164951667 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m
SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-server)[0x6120000087a0]{WAIT_WRITE_ACK}: State change
to ACTIVE (no timeout) (sbcap_smscb_peer_fsm.c:230)[0;m
[1;35m20241128164951667 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m
SMSCB(TTCN-3-46)[0x6120000081a0]{WAIT_WRITE_ACK}: Received Event WRITE_NACK
(sbcap_smscb_peer_fsm.c:231)[0;m
[1;32m20241128164951667 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m
SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-client)[0x612000008620]{INIT}: Received Event CREATE
(smscb_message_fsm.c:69)[0;m
[1;32m20241128164951667 [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;32m20241128164951667 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m
SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-client)[0x612000008620]{INIT}: State change to
WAIT_WRITE_ACK (T0, 10s) (sbcap_smscb_peer_fsm.c:119)[0;m
[1;32m20241128164951667 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m
SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-client)[0x612000008620]{WAIT_WRITE_ACK}: State change
to ACTIVE (no timeout) (sbcap_smscb_peer_fsm.c:230)[0;m
[1;35m20241128164951667 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m
SMSCB(TTCN-3-46)[0x6120000081a0]{WAIT_WRITE_ACK}: Received Event WRITE_NACK
(sbcap_smscb_peer_fsm.c:231)[0;m
[1;31m20241128164951667 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x6120000084a0]{INIT}: Received Event CREATE
(smscb_message_fsm.c:69)[0;m
[1;31m20241128164951667 [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;31m20241128164951667 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x6120000084a0]{INIT}: State change to
WAIT_WRITE_ACK (T0, 10s) (cbsp_smscb_peer_fsm.c:275)[0;m
[1;31m20241128164951667 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-client)[0x612000008320]{INIT}: Received Event CREATE
(smscb_message_fsm.c:69)[0;m
[1;31m20241128164951667 [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;31m20241128164951667 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-client)[0x612000008320]{INIT}: State change to
WAIT_WRITE_ACK (T0, 10s) (cbsp_smscb_peer_fsm.c:275)[0;m
[1;31m20241128164951667 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-client)[0x612000008320]{WAIT_WRITE_ACK}: State change
to ACTIVE (no timeout) (cbsp_smscb_peer_fsm.c:439)[0;m
[1;35m20241128164951667 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m
SMSCB(TTCN-3-46)[0x6120000081a0]{WAIT_WRITE_ACK}: Received Event WRITE_ACK
(cbsp_smscb_peer_fsm.c:440)[0;m
[1;31m20241128164951669 [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;31m20241128164951669 [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;31m20241128164951669 [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;31m20241128164951669 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x6120000084a0]{WAIT_WRITE_ACK}: Received
Event CBSP_WRITE_ACK (cbsp_link_fsm.c:344)[0;m
[1;31m20241128164951669 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x6120000084a0]{WAIT_WRITE_ACK}: Appending
CellId CI 50001 to Cell list (cbsp_smscb_peer_fsm.c:200)[0;m
[1;31m20241128164951669 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x6120000084a0]{WAIT_WRITE_ACK}: Appending
CellId CI 50002 to Cell list (cbsp_smscb_peer_fsm.c:200)[0;m
[1;31m20241128164951669 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x6120000084a0]{WAIT_WRITE_ACK}: Appending
CellId CI 50003 to Cell list (cbsp_smscb_peer_fsm.c:200)[0;m
[1;31m20241128164951669 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x6120000084a0]{WAIT_WRITE_ACK}: State change
to ACTIVE (no timeout) (cbsp_smscb_peer_fsm.c:294)[0;m
[1;35m20241128164951669 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m
SMSCB(TTCN-3-46)[0x6120000081a0]{WAIT_WRITE_ACK}: Received Event WRITE_ACK
(cbsp_smscb_peer_fsm.c:296)[0;m
[1;33m20241128164951669 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m
rest_it_op_complete(op=0x61b0000261e0) complete (rest_it_op.c:131)[0;m
[1;35m20241128164951669 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m
SMSCB(TTCN-3-46)[0x6120000081a0]{WAIT_WRITE_ACK}: State change to ACTIVE (no timeout)
(smscb_message_fsm.c:91)[0;m
[1;33m20241128164951669 [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;33m20241128164951669 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m /message POST
-> 201 (Created) (rest_api.c:588)[0;m
MTC@719ebcad609d: setverdict(pass): none -> pass
[1;33m20241128164953672 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m rest_it_op
enqueue from 140016481199808 (rest_it_op.c:57)[0;m
[1;33m20241128164953672 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m rest_it_op
wait.... (rest_it_op.c:66)[0;m
[1;33m20241128164953672 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m
rest2main_read_cb(op=0x61b0000268e0) from 140016523786944 (rest_it_op.c:93)[0;m
[1;35m20241128164953672 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m
SMSCB(TTCN-3-46)[0x6120000081a0]{ACTIVE}: Received Event DELETE (cbc_message.c:144)[0;m
[1;35m20241128164953672 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m
SMSCB(TTCN-3-46)[0x6120000081a0]{ACTIVE}: State change to WAIT_DELETE_ACK (T3, 15s)
(smscb_message_fsm.c:128)[0;m
[1;32m20241128164953672 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m
SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-server)[0x6120000087a0]{ACTIVE}: Received Event
DELETE (smscb_message_fsm.c:130)[0;m
[1;32m20241128164953672 [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;32m20241128164953672 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m
SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-server)[0x6120000087a0]{ACTIVE}: State change to
WAIT_DELETE_ACK (T3, 10s) (sbcap_smscb_peer_fsm.c:278)[0;m
[1;32m20241128164953672 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m
SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-server)[0x6120000087a0]{WAIT_DELETE_ACK}: State
change to DELETED (no timeout) (sbcap_smscb_peer_fsm.c:242)[0;m
[1;35m20241128164953672 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m
SMSCB(TTCN-3-46)[0x6120000081a0]{WAIT_DELETE_ACK}: Received Event DELETE_NACK
(sbcap_smscb_peer_fsm.c:243)[0;m
[1;32m20241128164953673 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m
SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-client)[0x612000008620]{ACTIVE}: Received Event
DELETE (smscb_message_fsm.c:130)[0;m
[1;32m20241128164953673 [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;32m20241128164953673 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m
SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-client)[0x612000008620]{ACTIVE}: State change to
WAIT_DELETE_ACK (T3, 10s) (sbcap_smscb_peer_fsm.c:278)[0;m
[1;32m20241128164953673 [1;32mDSBcAP[0;m[1;32m [1;32mINFO[0;m[1;32m
SMSCB-PEER-SBcAP(TTCN-3-46-ttcn3-mme-client)[0x612000008620]{WAIT_DELETE_ACK}: State
change to DELETED (no timeout) (sbcap_smscb_peer_fsm.c:242)[0;m
[1;35m20241128164953673 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m
SMSCB(TTCN-3-46)[0x6120000081a0]{WAIT_DELETE_ACK}: Received Event DELETE_NACK
(sbcap_smscb_peer_fsm.c:243)[0;m
[1;31m20241128164953673 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x6120000084a0]{ACTIVE}: Received Event DELETE
(smscb_message_fsm.c:130)[0;m
[1;31m20241128164953673 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
ttcn3-bsc-server: Transmitting KILL (cbsp_link.c:341)[0;m
[1;31m20241128164953673 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x6120000084a0]{ACTIVE}: State change to
WAIT_DELETE_ACK (T3, 10s) (cbsp_smscb_peer_fsm.c:490)[0;m
[1;31m20241128164953673 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-client)[0x612000008320]{ACTIVE}: Received Event DELETE
(smscb_message_fsm.c:130)[0;m
[1;31m20241128164953673 [1;33mDCBSP[0;m[1;31m [1;33mNOTICE[0;m[1;31m Cannot
transmit KILL: no connection (cbsp_link.c:330)[0;m
[1;31m20241128164953673 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-client)[0x612000008320]{ACTIVE}: State change to
WAIT_DELETE_ACK (T3, 10s) (cbsp_smscb_peer_fsm.c:490)[0;m
[1;31m20241128164953673 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-client)[0x612000008320]{WAIT_DELETE_ACK}: State change
to DELETED (no timeout) (cbsp_smscb_peer_fsm.c:451)[0;m
[1;35m20241128164953673 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m
SMSCB(TTCN-3-46)[0x6120000081a0]{WAIT_DELETE_ACK}: Received Event DELETE_ACK
(cbsp_smscb_peer_fsm.c:452)[0;m
[1;31m20241128164953674 [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;31m20241128164953674 [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;31m20241128164953674 [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;31m20241128164953674 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x6120000084a0]{WAIT_DELETE_ACK}: Received
Event CBSP_DELETE_ACK (cbsp_link_fsm.c:351)[0;m
[1;31m20241128164953675 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x6120000084a0]{WAIT_DELETE_ACK}: Appending
CellId CI 50001 to Cell list (cbsp_smscb_peer_fsm.c:200)[0;m
[1;31m20241128164953675 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x6120000084a0]{WAIT_DELETE_ACK}: Appending
CellId CI 50002 to Cell list (cbsp_smscb_peer_fsm.c:200)[0;m
[1;31m20241128164953675 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x6120000084a0]{WAIT_DELETE_ACK}: Appending
CellId CI 50003 to Cell list (cbsp_smscb_peer_fsm.c:200)[0;m
[1;31m20241128164953675 [1;32mDCBSP[0;m[1;31m [1;32mINFO[0;m[1;31m
SMSCB-PEER-CBSP(TTCN-3-46-ttcn3-bsc-server)[0x6120000084a0]{WAIT_DELETE_ACK}: State change
to DELETED (no timeout) (cbsp_smscb_peer_fsm.c:416)[0;m
[1;35m20241128164953675 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m
SMSCB(TTCN-3-46)[0x6120000081a0]{WAIT_DELETE_ACK}: Received Event DELETE_ACK
(cbsp_smscb_peer_fsm.c:418)[0;m
[1;33m20241128164953675 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m
rest_it_op_complete(op=0x61b0000268e0) complete (rest_it_op.c:131)[0;m
[1;35m20241128164953675 [1;32mDSMSCB[0;m[1;35m [1;32mINFO[0;m[1;35m
SMSCB(TTCN-3-46)[0x6120000081a0]{WAIT_DELETE_ACK}: State change to DELETED (no timeout)
(smscb_message_fsm.c:206)[0;m
[1;33m20241128164953675 [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;33m20241128164953675 [1;34mDREST[0;m[1;33m [1;34mDEBUG[0;m[1;33m /message
DELETE(46) -> 200 (OK) (rest_api.c:635)[0;m
MTC@719ebcad609d: setverdict(pass): pass -> pass, component reason not changed
MTC@719ebcad609d: setverdict(pass): pass -> pass, component reason not changed
TC_ecbe_create_delete_bsc_server-BSC1(26)@719ebcad609d: Final verdict of PTC: none
TC_ecbe_create_delete_bsc_server-BSC0(25)@719ebcad609d: Final verdict of PTC: none
[1;31m20241128164953677 [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;31m20241128164953678 [1;33mDCBSP[0;m[1;31m [1;33mNOTICE[0;m[1;31m
ttcn3-bsc-server: Disconnected. (cbsp_link.c:105)[0;m
[1;31m20241128164953678 [1;33mDCBSP[0;m[1;31m [1;33mNOTICE[0;m[1;31m
ttcn3-bsc-server: Reconnecting... (cbsp_link.c:106)[0;m
[38;5;23m20241128164953678 [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:43391){WAIT_RECONNECT} retrying
reconnect in 5 seconds... (stream_cli.c:239)[0;m
[1;31m20241128164953678 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m
CBSP-Link(ttcn3-bsc-server)[0x612000003220]{IDLE}: Received Event CLOSE.cmd
(cbsp_link.c:370)[0;m
[1;31m20241128164953678 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m
CBSP-Link(ttcn3-bsc-server)[0x612000003220]{IDLE}: Terminating (cause =
OSMO_FSM_TERM_REQUEST) (cbsp_link_fsm.c:170)[0;m
TC_ecbe_create_delete_bsc_server-BSC0-BSC0(27)@719ebcad609d: Final verdict of PTC: none
[1;31m20241128164953678 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m
CBSP-Link(ttcn3-bsc-server)[0x612000003220]{IDLE}: Freeing instance
(cbsp_link_fsm.c:170)[0;m
[1;31m20241128164953678 [1;34mDCBSP[0;m[1;31m [1;34mDEBUG[0;m[1;31m
CBSP-Link(ttcn3-bsc-server)[0x612000003220]{IDLE}: Deallocated (fsm.c:568)[0;m
=================================================================
MTC@719ebcad609d: Setting final verdict of the test case.
==5653==ERROR: AddressSanitizer: heap-use-after-free on address 0x619000009f74 at pc
0x7f58249420ea bp 0x7fffb00fa100 sp 0x7fffb00fa0f8
READ of size 1 at 0x619000009f74 thread T0
MTC@719ebcad609d: Local verdict of MTC: pass
MTC@719ebcad609d: Local verdict of PTC TC_ecbe_create_delete_bsc_server-BSC0(25): none
(pass -> pass)
MTC@719ebcad609d: Local verdict of PTC TC_ecbe_create_delete_bsc_server-BSC1(26): none
(pass -> pass)
MTC@719ebcad609d: Local verdict of PTC TC_ecbe_create_delete_bsc_server-BSC0-BSC0(27):
none (pass -> pass)
MTC@719ebcad609d: Test case TC_ecbe_create_delete_bsc_server finished. Verdict: pass
MTC@719ebcad609d: Starting external command
`<https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test-asan/ws/_cache/podman/osmo-ttcn3-hacks/ttcn3-tcpdump-stop.sh>
CBC_Tests.TC_ecbe_create_delete_bsc_server pass'.
Thu Nov 28 16:49:53 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
    #0 0x7f58249420e9  (/lib/x86_64-linux-gnu/libosmonetif.so.11+0xbb0e9)
    #1 0x7f5824bd4f75 in poll_disp_fds src/core/select.c:419
    #2 0x7f5824bd4f75 in _osmo_select_main src/core/select.c:457
    #3 0x7f5824bd5418 in osmo_select_main src/core/select.c:496
    #4 0x56308e16cade in main src/cbc_main.c:318
    #5 0x7f5824046249 in __libc_start_call_main ../sysdeps/nptl/libc_start_call_main.h:58
    #6 0x7f5824046304 in __libc_start_main_impl ../csu/libc-start.c:360
    #7 0x56308e16d1c0  (/usr/bin/osmo-cbc+0x681c0)

0x619000009f74 is located 1012 bytes inside of 1016-byte region
[0x619000009b80,0x619000009f78)
freed by thread T0 here:
    #0 0x7f5825eb76a8 in __interceptor_free
../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:52
    #1 0x7f58265885b1  (/lib/x86_64-linux-gnu/libtalloc.so.2+0x45b1)

previously allocated by thread T0 here:
    #0 0x7f5825eb89cf in __interceptor_malloc
../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:69
    #1 0x7f5826589e3d  (/lib/x86_64-linux-gnu/libtalloc.so.2+0x5e3d)

SUMMARY: AddressSanitizer: heap-use-after-free
(/lib/x86_64-linux-gnu/libosmonetif.so.11+0xbb0e9) 
Shadow bytes around the buggy address:
  0x0c327fff9390: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c327fff93a0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c327fff93b0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c327fff93c0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c327fff93d0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
=>0x0c327fff93e0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd[fd]fa
  0x0c327fff93f0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c327fff9400: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c327fff9410: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c327fff9420: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c327fff9430: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable:           00
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
  Left alloca redzone:     ca
  Right alloca redzone:    cb
==5653==ABORTING
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 86, in connect
    data = self.socket.recv(4096)
           ^^^^^^^^^^^^^^^^^^^^^^
ConnectionResetError: [Errno 104] Connection reset by peer
Waiting for packet dumper to finish... 0 (prev_count=-1, count=26052)
[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
Waiting for packet dumper to finish... 1 (prev_count=26052, count=42080)
MTC@719ebcad609d: External command
`<https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test-asan/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@719ebcad609d: Starting external command
`<https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test-asan/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 16:49:55 UTC 2024
/usr/bin/dumpcap -q -s 1520 -n -i any -w
"<https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test-asan/173/artifact/logs/testsuite/CBC_Tests.TC_ecbe_create_delete_mme_server.pcap">
><https://jenkins.osmocom.org/jenkins/job/ttcn3-cbc-test-asan/173/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-asan-20241128-1647-1bf0d7ef-0'][0m
719ebcad609d6dd317ebf88de545f7698204677002920df06143d1ad59387804
[1;34m[testenv] Stopping testsuite (1193481)[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-asan/173/artifact/lo… [0m
Build step 'Execute shell' marked build as failure
Recording test results
[Checks API] No suitable checks publisher found.