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/log... [0m Build step 'Execute shell' marked build as failure Recording test results [Checks API] No suitable checks publisher found.
jenkins-notifications@lists.osmocom.org
-
jenkins＠lists.osmocom.org