Actions
Bug #3686
closedosmo-bsc: heap-use-after-free during MO_MT call towards an MS not registered to th network
Start date:
11/09/2018
Due date:
% Done:
100%
Spec Reference:
Description
While doing some tests today, with master osmo-bsc:
20181109161154226 DLSCCP <0020> git/libosmo-sccp/src/sccp_scoc.c:1637 Received CO:CODT for local reference 3
20181109161154226 DLSCCP <0020> git/libosmo-sccp/src/sccp_scoc.c:1670 SCCP-SCOC(3)[0x612000005c20]{ACTIVE}: Received Event RCOC-DT1.ind
20181109161154226 DLSCCP <0020> git/libosmo-sccp/src/sccp_user.c:156 Delivering N-DATA.indication to SCCP User 'msc-0'
20181109161154226 DMSC <0007> git/osmo-bsc/src/osmo-bsc/osmo_bsc_sigtran.c:239 N-DATA.ind(3, 00 1d 01 0b 07 01 0a a1 91 81 a5 05 7c 06 c0 a8 1e 01 0f a2 7d 09 83 ff 57 82 80 84 3f 07 81 )
20181109161154226 DMSC <0007> git/osmo-bsc/src/osmo-bsc/a_reset.c:204 A-RESET(msc-0)[0x612000004120]{CONN}: Received Event EV_N_CONNECT
20181109161154226 DMSC <0007> git/osmo-bsc/src/osmo-bsc/osmo_bsc_bssap.c:859 Rx MSC DT1 BSSMAP ASSIGNMENT REQ
20181109161154226 DMSC <0007> git/osmo-bsc/src/osmo-bsc/osmo_bsc_bssap.c:729 Found matching audio type: full rate SPEECH_V1 for channel_type = { ch_indctr=0x1, ch_rate_type=0xa, perm_spch=[ 21 11 01 25 05 ] }
20181109161154226 DMSC <0007> git/osmo-bsc/src/osmo-bsc/osmo_bsc_bssap.c:761 SUBSCR_CONN(conn3)[0x612000005920]{ACTIVE}: Received Event ASSIGNMENT_START
20181109161154226 DMSC <0007> git/osmo-bsc/src/osmo-bsc/bsc_subscr_conn_fsm.c:359 SUBSCR_CONN(conn3)[0x612000005920]{ACTIVE}: state_chg to ASSIGNMENT
20181109161154226 DMSC <0007> git/osmo-bsc/src/osmo-bsc/assignment_fsm.c:310 Assignment: incrementing rate counter: assignment:attempted Assignment attempts.
20181109161154226 DAS <0012> git/libosmocore/src/fsm.c:299 assignment(conn3)[0x612000005da0]{WAIT_LCHAN_ACTIVE}: Allocated
20181109161154226 DAS <0012> git/libosmocore/src/fsm.c:329 assignment(conn3)[0x612000005da0]{WAIT_LCHAN_ACTIVE}: is child of SUBSCR_CONN(conn3)[0x612000005920]
20181109161154226 DRLL <0000> git/osmo-bsc/src/osmo-bsc/lchan_select.c:159 (bts=0) lchan_select_by_type(TCH_F)
20181109161154226 DRLL <0000> git/osmo-bsc/src/osmo-bsc/lchan_select.c:71 looking for lchan TCH/F: (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4,state=IN_USE) is != TCH/F
20181109161154226 DRLL <0000> git/osmo-bsc/src/osmo-bsc/lchan_select.c:86 looking for lchan TCH/F: (bts=0,trx=0,ts=1,pchan=TCH/F,state=UNUSED) ss=0 is available
20181109161154226 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_select.c:253 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{UNUSED}: (type=TCH_F) Selected
20181109161154226 DAS <0012> git/osmo-bsc/src/osmo-bsc/assignment_fsm.c:378 assignment(conn3_0-0-1-TCH_F-0)[0x612000005da0]{WAIT_LCHAN_ACTIVE}: (bts=0,trx=0,ts=1,ss=0) Starting Assignment: chan_mode=SPEECH_V1, full_rate=1, aoip=yes MSC-rtp=192.168.30.1:4002
20181109161154226 DAS <0012> git/osmo-bsc/src/osmo-bsc/assignment_fsm.c:380 assignment(conn3_0-0-1-TCH_F-0)[0x612000005da0]{WAIT_LCHAN_ACTIVE}: state_chg to WAIT_LCHAN_ACTIVE
20181109161154226 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:318 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{UNUSED}: Received Event LCHAN_EV_ACTIVATE
20181109161154226 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:547 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{UNUSED}: state_chg to WAIT_TS_READY
20181109161154226 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:573 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_TS_READY}: (type=TCH_F) Activation requested: FOR_ASSIGNMENT voice=yes MGW-ci=new type=TCH_F tch-mode=SPEECH_V1
20181109161154226 DTS <0011> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:577 timeslot(0-0-1-TCH_F)[0x612000002920]{UNUSED}: Received Event TS_EV_LCHAN_REQUESTED
20181109161154226 DTS <0011> git/osmo-bsc/src/osmo-bsc/timeslot_fsm.c:328 timeslot(0-0-1-TCH_F)[0x612000002920]{UNUSED}: state_chg to IN_USE
20181109161154226 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/timeslot_fsm.c:104 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_TS_READY}: Received Event LCHAN_EV_TS_READY
20181109161154226 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:591 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_TS_READY}: state_chg to WAIT_ACTIV_ACK
20181109161154226 DRSL <0003> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:476 (bts=0,trx=0,ts=1,pchan=TCH/F,state=IN_USE) Tx RSL Channel Activate with act_type=INTRA_NORM_ASS
20181109161154226 DCHAN <0010> git/libosmocore/src/fsm.c:299 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{WAIT_MGW_ENDPOINT_AVAILABLE}: Allocated
20181109161154226 DCHAN <0010> git/libosmocore/src/fsm.c:329 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{WAIT_MGW_ENDPOINT_AVAILABLE}: is child of lchan(0-0-1-TCH_F-0)[0x6120000048a0]
20181109161154226 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_rtp_fsm.c:118 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{WAIT_MGW_ENDPOINT_AVAILABLE}: state_chg to WAIT_MGW_ENDPOINT_AVAILABLE
20181109161154226 DRSL <0003> git/libosmocore/src/fsm.c:299 mgw-endpoint(conn3)[0x6120000060a0]{UNUSED}: Allocated
20181109161154226 DRSL <0003> git/libosmocore/src/fsm.c:329 mgw-endpoint(conn3)[0x6120000060a0]{UNUSED}: is child of SUBSCR_CONN(conn3)[0x612000005920]
20181109161154227 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:441 mgw-endpoint(conn3)[0x6120000060a0]{UNUSED}: (rtpbridge/*@mgw) CI[0] to-BTS: CRCX :0: notify=lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]
20181109161154227 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:482 mgw-endpoint(conn3)[0x6120000060a0]{UNUSED}: (rtpbridge/*@mgw) CI[0] to-BTS: CRCX :0: Scheduling
20181109161154227 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:485 mgw-endpoint(conn3)[0x6120000060a0]{UNUSED}: state_chg to WAIT_MGW_RESPONSE
20181109161154227 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:505 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: (rtpbridge/*@mgw) CI[0] to-BTS: CRCX :0: Sending
20181109161154227 DRLL <0000> git/libosmocore/src/fsm.c:299 MGCP_CONN(conn3)[0x612000006220]{ST_CRCX}: Allocated
20181109161154227 DRLL <0000> git/libosmocore/src/fsm.c:329 MGCP_CONN(conn3)[0x612000006220]{ST_CRCX}: is child of mgw-endpoint(conn3)[0x6120000060a0]
20181109161154227 DRLL <0000> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:602 MGCP_CONN(conn3)[0x612000006220]{ST_CRCX}: Received Event EV_CRCX
20181109161154227 DRLL <0000> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:197 MGCP_CONN(conn3)[0x612000006220]{ST_CRCX}: MGW/CRCX: creating connection on MGW endpoint:rtpbridge/*@mgw...
20181109161154227 DLMGCP <0023> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client.c:953 Queued 75 bytes for MGCP GW
20181109161154227 DRLL <0000> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:213 MGCP_CONN(conn3)[0x612000006220]{ST_CRCX}: state_chg to ST_CRCX_RESP
20181109161154227 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:625 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: (rtpbridge/*@mgw) Sent messages: 1
20181109161154227 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:578 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: (rtpbridge/*@mgw) CI[0] to-BTS: CRCX :0: waiting for response
20181109161154227 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:598 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: (rtpbridge/*@mgw) CI in use: 1, waiting for response: 1
20181109161154227 DLMGCP <0023> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client.c:749 Tx MGCP msg to MGCP GW: 'CRCX 1 rtpbridge/*@mgw MGCP 1.0'
20181109161154227 DLMGCP <0023> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client.c:751 Sending msg to MGCP GW size: 75
20181109161154227 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:356 TX 2: 08 21 01 09 03 01 06 04 00 01 08 01 05 06 64 09 e3 68 72 00 04 00 0d 07 18 00
20181109161154227 DRLL <0000> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:249 MGCP_CONN(to-BTS)[0x612000006220]{ST_CRCX_RESP}: MGW/CRCX: MGW responded with CI: 9EEDE97E
20181109161154227 DRLL <0000> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:257 MGCP_CONN(to-BTS)[0x612000006220]{ST_CRCX_RESP}: MGW/CRCX: MGW responded with address 192.168.30.1:4006
20181109161154227 DRLL <0000> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:281 MGCP_CONN(to-BTS)[0x612000006220]{ST_CRCX_RESP}: Received Event EV_CRCX_RESP
20181109161154227 DRLL <0000> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:291 MGCP_CONN(to-BTS)[0x612000006220]{ST_CRCX_RESP}: state_chg to ST_READY
20181109161154227 DRSL <0003> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:298 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: Received Event MGW Response for CI #0
20181109161154227 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:346 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: (rtpbridge/1@mgw) CI[0] to-BTS CI=9EEDE97E: received successful response to CRCX RTP=rtpbridge/1@mgw:192.168.30.1:4006
20181109161154227 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:349 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{WAIT_MGW_ENDPOINT_AVAILABLE}: Received Event LCHAN_RTP_EV_MGW_ENDPOINT_AVAILABLE
20181109161154227 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_rtp_fsm.c:178 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{WAIT_MGW_ENDPOINT_AVAILABLE}: MGW endpoint: rtpbridge/1@mgw:192.168.30.1:4006
20181109161154227 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_rtp_fsm.c:179 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{WAIT_MGW_ENDPOINT_AVAILABLE}: state_chg to WAIT_LCHAN_READY
20181109161154227 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:580 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: (rtpbridge/1@mgw) CI[0] to-BTS CI=9EEDE97E: CRCX :0: rtpbridge/1@mgw:192.168.30.1:4006
20181109161154227 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:598 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: (rtpbridge/1@mgw) CI in use: 1, waiting for response: 0
20181109161154227 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:609 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: state_chg to IN_USE
20181109161154227 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:580 mgw-endpoint(conn3)[0x6120000060a0]{IN_USE}: (rtpbridge/1@mgw) CI[0] to-BTS CI=9EEDE97E: CRCX :0: rtpbridge/1@mgw:192.168.30.1:4006
20181109161154424 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 08 28 01 20 1b 02 19 03 3f 3f 00 04 00 0a 70 08 0b 00 12 06 15 3f 3f 00 00 00 00 00 00 00 00 00 00 00 00 00 00 25 42
20181109161154424 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1129 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{ESTABLISHED}: (type=SDCCH) Rx MEAS_RES
20181109161154424 DRSL <0003> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1059 (bts=0,trx=0,ts=0,ss=0): meas_rep_count++=3 meas_rep_last_seen_nr=2
20181109161154424 DMEAS <0006> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:933 [(bts=0,trx=0,ts=0,ss=0)] MEASUREMENT RESULT NR=2 RXL-FULL-ul=-47dBm RXL-SUB-ul=-47dBm RXQ-FULL-ul=0 RXQ-SUB-ul=0 BS_POWER=0 MS_TO=3 L1_MS_PWR= 2dBm L1_FPC=0 L1_TA=8 RXL-FULL-dl=-47dBm RXL-SUB-dl=-47dBm RXQ-FULL-dl=0 RXQ-SUB-dl=0 NUM_NEIGH=0
20181109161154468 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 08 22 01 09 08 8c 88
20181109161154468 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1129 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_ACTIV_ACK}: (type=TCH_F) Rx CHAN_ACTIV_ACK
20181109161154468 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1141 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_ACTIV_ACK}: Received Event LCHAN_EV_RSL_CHAN_ACTIV_ACK
20181109161154468 DAS <0012> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:735 assignment(conn3_0-0-1-TCH_F-0)[0x612000005da0]{WAIT_LCHAN_ACTIVE}: Received Event ASSIGNMENT_EV_LCHAN_ACTIVE
20181109161154468 DAS <0012> git/osmo-bsc/src/osmo-bsc/assignment_fsm.c:405 assignment(conn3_0-0-1-TCH_F-0)[0x612000005da0]{WAIT_LCHAN_ACTIVE}: state_chg to WAIT_RR_ASS_COMPLETE
20181109161154468 DRR <0002> git/osmo-bsc/src/osmo-bsc/gsm_04_08_rr.c:500 -> ASSIGNMENT COMMAND tch_mode=0x01
20181109161154468 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:764 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_ACTIV_ACK}: state_chg to WAIT_RLL_RTP_ESTABLISH
20181109161154468 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:771 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{WAIT_LCHAN_READY}: Received Event LCHAN_RTP_EV_LCHAN_READY
20181109161154468 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_rtp_fsm.c:248 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{WAIT_LCHAN_READY}: state_chg to WAIT_IPACC_CRCX_ACK
20181109161154468 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1848 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_RLL_RTP_ESTABLISH}: (type=TCH_F) Sending IPACC CRCX to BTS: speech_mode=0x10 RTP_PAYLOAD=3
20181109161154468 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:356 TX 2: 03 01 01 20 02 00 0b 00 08 06 2e 09 e3 68 07 63 01
20181109161154469 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:356 TX 2: 7e 70 01 09 f4 10 f2 03
20181109161154517 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 08 28 01 09 1b 00 19 03 04 03 28 04 00 25 3f
20181109161154517 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1129 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_RLL_RTP_ESTABLISH}: (type=TCH_F) Rx MEAS_RES
20181109161154517 DRSL <0003> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1059 (bts=0,trx=0,ts=1,ss=0): meas_rep_count++=1 meas_rep_last_seen_nr=0
20181109161154517 DMEAS <0006> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:933 [(bts=0,trx=0,ts=1,ss=0)] MEASUREMENT RESULT NR=0 RXL-FULL-ul=-106dBm RXL-SUB-ul=-107dBm RXQ-FULL-ul=5 RXQ-SUB-ul=0 BS_POWER=0 MS_TO=0 NOT VALID NUM_NEIGH=0
20181109161154521 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 7e 71 01 09 f8 00 03 f3 0f a6 f5 c0 a8 1e 64
20181109161154521 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:2010 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_RLL_RTP_ESTABLISH}: (type=TCH_F) Rx IPAC_CRCX_ACK
20181109161154521 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1827 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_RLL_RTP_ESTABLISH}: (type=TCH_F) Rx IPACC CRCX ACK: BTS=192.168.30.100:4006 conn_id=3 rtp_payload2=0x00 speech_mode=0x10
20181109161154521 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1919 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{WAIT_IPACC_CRCX_ACK}: Received Event LCHAN_RTP_EV_IPACC_CRCX_ACK
20181109161154521 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_rtp_fsm.c:300 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{WAIT_IPACC_CRCX_ACK}: state_chg to WAIT_IPACC_MDCX_ACK
20181109161154521 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1889 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_RLL_RTP_ESTABLISH}: (type=TCH_F) Sending IPACC MDCX to BTS: 192.168.30.1:4006 rtp_payload=3 rtp_payload2=0 conn_id=3 speech_mode=0x00
20181109161154521 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:356 TX 2: 7e 73 01 09 f8 00 03 f0 c0 a8 1e 01 f1 0f a6 f4 00 f2 03
20181109161154524 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 7e 74 01 09 f8 00 03
20181109161154524 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:2010 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_RLL_RTP_ESTABLISH}: (type=TCH_F) Rx IPAC_MDCX_ACK
20181109161154524 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1827 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_RLL_RTP_ESTABLISH}: (type=TCH_F) Rx IPACC MDCX ACK: BTS=192.168.30.100:4006 conn_id=3 rtp_payload2=0x00 speech_mode=0x00
20181109161154524 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1957 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{WAIT_IPACC_MDCX_ACK}: Received Event LCHAN_RTP_EV_IPACC_MDCX_ACK
20181109161154524 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_rtp_fsm.c:240 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{WAIT_IPACC_MDCX_ACK}: state_chg to WAIT_MGW_ENDPOINT_CONFIGURED
20181109161154524 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_rtp_fsm.c:430 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{WAIT_MGW_ENDPOINT_CONFIGURED}: Sending BTS side RTP port info 192.168.30.100:4006 to MGW rtpbridge/1@mgw:192.168.30.1:4006
20181109161154524 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:441 mgw-endpoint(conn3)[0x6120000060a0]{IN_USE}: (rtpbridge/1@mgw) CI[0] to-BTS CI=9EEDE97E: MDCX :0: notify=lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]
20181109161154524 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:482 mgw-endpoint(conn3)[0x6120000060a0]{IN_USE}: (rtpbridge/1@mgw) CI[0] to-BTS CI=9EEDE97E: MDCX 192.168.30.100:4006: Scheduling
20181109161154524 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:485 mgw-endpoint(conn3)[0x6120000060a0]{IN_USE}: state_chg to WAIT_MGW_RESPONSE
20181109161154524 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:519 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: (rtpbridge/1@mgw) CI[0] to-BTS CI=9EEDE97E: MDCX 192.168.30.100:4006: Sending
20181109161154524 DRLL <0000> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:660 MGCP_CONN(to-BTS)[0x612000006220]{ST_READY}: Received Event EV_MDCX
20181109161154525 DLMGCP <0023> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client.c:953 Queued 175 bytes for MGCP GW
20181109161154525 DRLL <0000> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:347 MGCP_CONN(to-BTS)[0x612000006220]{ST_READY}: state_chg to ST_MDCX_RESP
20181109161154525 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:625 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: (rtpbridge/1@mgw) Sent messages: 1
20181109161154525 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:578 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: (rtpbridge/1@mgw) CI[0] to-BTS CI=9EEDE97E: MDCX 192.168.30.100:4006: waiting for response
20181109161154525 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:598 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: (rtpbridge/1@mgw) CI in use: 1, waiting for response: 1
20181109161154525 DLMGCP <0023> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client.c:749 Tx MGCP msg to MGCP GW: 'MDCX 2 rtpbridge/1@mgw MGCP 1.0'
20181109161154525 DLMGCP <0023> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client.c:751 Sending msg to MGCP GW size: 175
20181109161154525 DRLL <0000> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:375 MGCP_CONN(to-BTS)[0x612000006220]{ST_MDCX_RESP}: MGW/MDCX: MGW responded with address 192.168.30.1:4006
20181109161154525 DRLL <0000> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:380 MGCP_CONN(to-BTS)[0x612000006220]{ST_MDCX_RESP}: Received Event EV_MDCX_RESP
20181109161154525 DRLL <0000> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:390 MGCP_CONN(to-BTS)[0x612000006220]{ST_MDCX_RESP}: state_chg to ST_READY
20181109161154525 DRSL <0003> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:397 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: Received Event MGW Response for CI #0
20181109161154525 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:346 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: (rtpbridge/1@mgw) CI[0] to-BTS CI=9EEDE97E: received successful response to MDCX RTP=rtpbridge/1@mgw:192.168.30.1:4006
20181109161154525 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:349 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{WAIT_MGW_ENDPOINT_CONFIGURED}: Received Event LCHAN_RTP_EV_MGW_ENDPOINT_CONFIGURED
20181109161154525 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_rtp_fsm.c:467 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{WAIT_MGW_ENDPOINT_CONFIGURED}: state_chg to READY
20181109161154525 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_rtp_fsm.c:490 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_RLL_RTP_ESTABLISH}: Received Event LCHAN_EV_RTP_READY
20181109161154525 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:580 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: (rtpbridge/1@mgw) CI[0] to-BTS CI=9EEDE97E: MDCX 192.168.30.100:4006: rtpbridge/1@mgw:192.168.30.1:4006
20181109161154525 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:598 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: (rtpbridge/1@mgw) CI in use: 1, waiting for response: 0
20181109161154525 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:609 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: state_chg to IN_USE
20181109161154525 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:580 mgw-endpoint(conn3)[0x6120000060a0]{IN_USE}: (rtpbridge/1@mgw) CI[0] to-BTS CI=9EEDE97E: MDCX 192.168.30.100:4006: rtpbridge/1@mgw:192.168.30.1:4006
20181109161154895 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 08 28 01 20 1b 03 19 03 3f 3f 00 04 00 0a 70 08 0b 00 12 06 15 bf 3f 00 00 00 00 00 00 00 00 00 00 00 00 00 00 25 47
20181109161154895 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1129 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{ESTABLISHED}: (type=SDCCH) Rx MEAS_RES
20181109161154895 DRSL <0003> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1059 (bts=0,trx=0,ts=0,ss=0): meas_rep_count++=4 meas_rep_last_seen_nr=3
20181109161154895 DMEAS <0006> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:933 [(bts=0,trx=0,ts=0,ss=0)] MEASUREMENT RESULT NR=3 RXL-FULL-ul=-47dBm RXL-SUB-ul=-47dBm RXQ-FULL-ul=0 RXQ-SUB-ul=0 BS_POWER=0 MS_TO=8 L1_MS_PWR= 2dBm L1_FPC=0 L1_TA=8 BA1 RXL-FULL-dl=-47dBm RXL-SUB-dl=-47dBm RXQ-FULL-dl=0 RXQ-SUB-dl=0 NUM_NEIGH=0
20181109161154997 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 08 28 01 09 1b 01 19 03 03 03 3f 04 00 25 3f
20181109161154998 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1129 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_RLL_RTP_ESTABLISH}: (type=TCH_F) Rx MEAS_RES
20181109161154998 DRSL <0003> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1059 (bts=0,trx=0,ts=1,ss=0): meas_rep_count++=2 meas_rep_last_seen_nr=1
20181109161154998 DMEAS <0006> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:933 [(bts=0,trx=0,ts=1,ss=0)] MEASUREMENT RESULT NR=1 RXL-FULL-ul=-107dBm RXL-SUB-ul=-107dBm RXQ-FULL-ul=7 RXQ-SUB-ul=7 BS_POWER=0 MS_TO=0 NOT VALID NUM_NEIGH=0
20181109161155162 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 02 02 01 20 02 00 0b 00 02 03 aa
20181109161155163 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1605 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{ESTABLISHED}: (type=SDCCH) SAPI=0 DATA INDICATION
20181109161155163 DMSC <0007> git/osmo-bsc/src/osmo-bsc/gsm_08_08.c:602 Tx MSC DTAP LINK_ID=0x00
20181109161155163 DMSC <0007> git/osmo-bsc/src/osmo-bsc/gsm_08_08.c:624 SUBSCR_CONN(conn3)[0x612000005920]{ASSIGNMENT}: Received Event MO_DTAP
20181109161155163 DMSC <0007> git/osmo-bsc/src/osmo-bsc/osmo_bsc_sigtran.c:370 Tx MSC: DTAP
20181109161155163 DMSC <0007> git/osmo-bsc/src/osmo-bsc/osmo_bsc_sigtran.c:390 Sending connection (id=3) oriented data to MSC: RI=SSN_PC,PC=0.23.1,SSN=BSSAP (01 00 02 03 aa )
20181109161155163 DLSCCP <0020> git/libosmo-sccp/src/sccp_scoc.c:1704 Received SCCP User Primitive N-DATA.request)
20181109161155163 DLSCCP <0020> git/libosmo-sccp/src/sccp_scoc.c:1746 SCCP-SCOC(3)[0x612000005c20]{ACTIVE}: Received Event N-DATA.req
20181109161155163 DLSS7 <001f> git/libosmo-sccp/src/sccp_scrc.c:398 sccp_scrc_rx_scoc_conn_msg: HDR=(CO:CODT,V=0,LEN=0),
PART(T=Routing Context,L=4,D=00000000),
PART(T=Destination Reference,L=4,D=00000002),
PART(T=Data,L=5,D=01000203aa)
20181109161155163 DLSS7 <001f> git/libosmo-sccp/src/osmo_ss7_hmrt.c:278 m3ua_hmdc_rx_from_l2(): dpc=185=0.23.1 not local, message is for routing
20181109161155163 DLSS7 <001f> git/libosmo-sccp/src/osmo_ss7_hmrt.c:227 Found route for dpc=185=0.23.1: pc=0=0.0.0 mask=0x0=0.0.0 via AS as-clnt-msc-0 proto=m3ua
20181109161155163 DLSS7 <001f> git/libosmo-sccp/src/osmo_ss7_hmrt.c:233 rt->dest.as proto is M3UA for dpc=185=0.23.1
20181109161155163 DLSS7 <001f> git/libosmo-sccp/src/m3ua.c:507 XUA_AS(as-clnt-msc-0)[0x612000003820]{AS_ACTIVE}: Received Event AS-TRANSFER.req
20181109161155163 DLINP <0015> git/libosmo-netif/src/stream.c:279 connected write
20181109161155163 DLINP <0015> git/libosmo-netif/src/stream.c:204 sending data
20181109161155163 DLINP <0015> git/libosmo-netif/src/stream.c:279 connected write
20181109161155163 DLINP <0015> git/libosmo-netif/src/stream.c:204 sending data
20181109161155167 DLINP <0015> git/libosmo-netif/src/stream.c:275 connected read
20181109161155167 DLINP <0015> git/libosmo-netif/src/stream.c:189 message received
20181109161155168 DLSS7 <001f> git/libosmo-sccp/src/osmo_ss7.c:1561 asp-asp-clnt-msc-0: xua_cli_read_cb(): sctp_recvmsg() returned 48 (flags=0x80)
20181109161155168 DLM3UA <0022> git/libosmo-sccp/src/m3ua.c:722 asp-asp-clnt-msc-0: Received M3UA Message (XFER:DATA)
20181109161155168 DLM3UA <0022> git/libosmo-sccp/src/m3ua.c:541 asp-asp-clnt-msc-0: m3ua_rx_xfer
20181109161155168 DLM3UA <0022> git/libosmo-sccp/src/m3ua.c:580 asp-asp-clnt-msc-0: m3ua_rx_xfer(): M3UA data header: opc=185=0.23.1 dpc=187=0.23.3
20181109161155168 DLSS7 <001f> git/libosmo-sccp/src/osmo_ss7_hmrt.c:274 m3ua_hmdc_rx_from_l2(): found dpc=187=0.23.3 as local
20181109161155168 DLSS7 <001f> git/libosmo-sccp/src/sccp_scrc.c:450 scrc_rx_mtp_xfer_ind_xua: HDR=(CO:CODT,V=0,LEN=0),
PART(T=Destination Reference,L=4,D=00000003),
PART(T=Segmentation,L=4,D=00000000),
PART(T=Data,L=6,D=000420040109)
20181109161155168 DLSCCP <0020> git/libosmo-sccp/src/sccp_scoc.c:1637 Received CO:CODT for local reference 3
20181109161155168 DLSCCP <0020> git/libosmo-sccp/src/sccp_scoc.c:1670 SCCP-SCOC(3)[0x612000005c20]{ACTIVE}: Received Event RCOC-DT1.ind
20181109161155168 DLSCCP <0020> git/libosmo-sccp/src/sccp_user.c:156 Delivering N-DATA.indication to SCCP User 'msc-0'
20181109161155168 DMSC <0007> git/osmo-bsc/src/osmo-bsc/osmo_bsc_sigtran.c:239 N-DATA.ind(3, 00 04 20 04 01 09 )
20181109161155168 DMSC <0007> git/osmo-bsc/src/osmo-bsc/a_reset.c:204 A-RESET(msc-0)[0x612000004120]{CONN}: Received Event EV_N_CONNECT
20181109161155168 DMSC <0007> git/osmo-bsc/src/osmo-bsc/osmo_bsc_bssap.c:859 Rx MSC DT1 BSSMAP CLEAR COMMAND
20181109161155168 DMSC <0007> git/osmo-bsc/src/osmo-bsc/osmo_bsc_bssap.c:863 SUBSCR_CONN(conn3)[0x612000005920]{ASSIGNMENT}: Received Event CLEAR_CMD
20181109161155168 DMSC <0007> git/osmo-bsc/src/osmo-bsc/bsc_subscr_conn_fsm.c:695 SUBSCR_CONN(conn3)[0x612000005920]{ASSIGNMENT}: state_chg to CLEARING
20181109161155168 DMSC <0007> git/osmo-bsc/src/osmo-bsc/bsc_subscr_conn_fsm.c:696 SUBSCR_CONN(conn3)[0x612000005920]{CLEARING}: Releasing all lchans (if any) after BSSMAP Clear Command
20181109161155168 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:1313 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{READY}: Received Event LCHAN_RTP_EV_ROLLBACK
20181109161155168 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_rtp_fsm.c:506 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{READY}: state_chg to ROLLBACK
20181109161155168 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_rtp_fsm.c:520 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{ROLLBACK}: Terminating (cause = OSMO_FSM_TERM_REQUEST)
20181109161155168 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_rtp_fsm.c:520 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{ROLLBACK}: Removing from parent lchan(0-0-1-TCH_F-0)[0x6120000048a0]
20181109161155168 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:441 mgw-endpoint(conn3)[0x6120000060a0]{IN_USE}: (rtpbridge/1@mgw) CI[0] to-BTS CI=9EEDE97E: DLCX :0: notify=NULL
20181109161155168 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:482 mgw-endpoint(conn3)[0x6120000060a0]{IN_USE}: (rtpbridge/1@mgw) CI[0] to-BTS CI=9EEDE97E: DLCX :0: Scheduling
20181109161155168 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:485 mgw-endpoint(conn3)[0x6120000060a0]{IN_USE}: state_chg to WAIT_MGW_RESPONSE
20181109161155168 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:530 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: (rtpbridge/1@mgw) CI[0] to-BTS CI=9EEDE97E: Sending MGCP: DLCX 9EEDE97E
20181109161155169 DRLL <0000> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:686 MGCP_CONN(to-BTS)[0x612000006220]{ST_READY}: Received Event EV_DLCX
20181109161155169 DLMGCP <0023> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client.c:953 Queued 52 bytes for MGCP GW
20181109161155169 DRLL <0000> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:347 MGCP_CONN(to-BTS)[0x612000006220]{ST_READY}: state_chg to ST_DLCX_RESP
20181109161155169 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:625 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: (rtpbridge/1@mgw) Sent messages: 1
20181109161155169 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:598 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: (rtpbridge/1@mgw) CI in use: 0, waiting for response: 0
20181109161155169 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:603 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
20181109161155169 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:603 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: Removing from parent SUBSCR_CONN(conn3)[0x612000005920]
20181109161155169 DRSL <0003> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:603 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: Freeing instance
20181109161155169 DRSL <0003> git/libosmocore/src/fsm.c:381 mgw-endpoint(conn3)[0x6120000060a0]{WAIT_MGW_RESPONSE}: Deallocated
20181109161155169 DMSC <0007> git/osmo-bsc/src/osmo-bsc/mgw_endpoint_fsm.c:603 SUBSCR_CONN(conn3)[0x612000005920]{CLEARING}: Received Event FORGET_MGW_ENDPOINT
20181109161155169 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_rtp_fsm.c:741 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_RLL_RTP_ESTABLISH}: Received Event LCHAN_EV_RTP_RELEASED
20181109161155169 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_rtp_fsm.c:520 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{ROLLBACK}: Freeing instance
20181109161155169 DCHAN <0010> git/libosmocore/src/fsm.c:381 lchan_rtp(0-0-1-TCH_F-0)[0x612000005f20]{ROLLBACK}: Deallocated
20181109161155169 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_rtp_fsm.c:520 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_RLL_RTP_ESTABLISH}: Received Event LCHAN_EV_RTP_RELEASED
20181109161155169 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:1323 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_RLL_RTP_ESTABLISH}: state_chg to WAIT_RF_RELEASE_ACK
20181109161155169 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:1337 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{ESTABLISHED}: state_chg to WAIT_RLL_RTP_RELEASED
20181109161155169 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:938 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_RLL_RTP_RELEASED}: (type=SDCCH) SAPI[0] = 1
20181109161155169 DRSL <0003> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:638 (bts=0,trx=0,ts=0,ss=0) DEACTivate SACCH CMD
20181109161155169 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:972 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_RLL_RTP_RELEASED}: state_chg to WAIT_BEFORE_RF_RELEASE
20181109161155169 DMSC <0007> git/osmo-bsc/src/osmo-bsc/osmo_bsc_sigtran.c:367 Tx MSC: BSSMAP: CLEAR COMPLETE
20181109161155169 DMSC <0007> git/osmo-bsc/src/osmo-bsc/osmo_bsc_sigtran.c:390 Sending connection (id=3) oriented data to MSC: RI=SSN_PC,PC=0.23.1,SSN=BSSAP (00 01 21 )
20181109161155169 DLSCCP <0020> git/libosmo-sccp/src/sccp_scoc.c:1704 Received SCCP User Primitive N-DATA.request)
20181109161155169 DLSCCP <0020> git/libosmo-sccp/src/sccp_scoc.c:1746 SCCP-SCOC(3)[0x612000005c20]{ACTIVE}: Received Event N-DATA.req
20181109161155169 DLSS7 <001f> git/libosmo-sccp/src/sccp_scrc.c:398 sccp_scrc_rx_scoc_conn_msg: HDR=(CO:CODT,V=0,LEN=0),
PART(T=Routing Context,L=4,D=00000000),
PART(T=Destination Reference,L=4,D=00000002),
PART(T=Data,L=3,D=000121)
20181109161155169 DLSS7 <001f> git/libosmo-sccp/src/osmo_ss7_hmrt.c:278 m3ua_hmdc_rx_from_l2(): dpc=185=0.23.1 not local, message is for routing
20181109161155170 DLSS7 <001f> git/libosmo-sccp/src/osmo_ss7_hmrt.c:227 Found route for dpc=185=0.23.1: pc=0=0.0.0 mask=0x0=0.0.0 via AS as-clnt-msc-0 proto=m3ua
20181109161155170 DLSS7 <001f> git/libosmo-sccp/src/osmo_ss7_hmrt.c:233 rt->dest.as proto is M3UA for dpc=185=0.23.1
20181109161155170 DLSS7 <001f> git/libosmo-sccp/src/m3ua.c:507 XUA_AS(as-clnt-msc-0)[0x612000003820]{AS_ACTIVE}: Received Event AS-TRANSFER.req
20181109161155170 DLMGCP <0023> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client.c:749 Tx MGCP msg to MGCP GW: 'DLCX 3 rtpbridge/1@mgw MGCP 1.0'
20181109161155170 DLMGCP <0023> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client.c:751 Sending msg to MGCP GW size: 52
20181109161155170 DLINP <0015> git/libosmo-netif/src/stream.c:279 connected write
20181109161155170 DLINP <0015> git/libosmo-netif/src/stream.c:204 sending data
20181109161155170 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:356 TX 2: 08 2e 01 09
20181109161155170 DLINP <0015> git/libosmo-netif/src/stream.c:279 connected write
20181109161155170 DLINP <0015> git/libosmo-netif/src/stream.c:204 sending data
20181109161155170 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:356 TX 2: 08 25 01 20
20181109161155171 DRLL <0000> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:423 MGCP_CONN(to-BTS)[0x612000006220]{ST_DLCX_RESP}: Received Event EV_DLCX_RESP
20181109161155171 DRLL <0000> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:439 MGCP_CONN(to-BTS)[0x612000006220]{ST_DLCX_RESP}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
20181109161155171 DRLL <0000> git/osmo-mgw/src/libosmo-mgcp-client/mgcp_client_fsm.c:439 MGCP_CONN(to-BTS)[0x612000006220]{ST_DLCX_RESP}: Freeing instance
20181109161155171 DRLL <0000> git/libosmocore/src/fsm.c:381 MGCP_CONN(to-BTS)[0x612000006220]{ST_DLCX_RESP}: Deallocated
20181109161155174 DLINP <0015> git/libosmo-netif/src/stream.c:275 connected read
20181109161155174 DLINP <0015> git/libosmo-netif/src/stream.c:189 message received
20181109161155174 DLSS7 <001f> git/libosmo-sccp/src/osmo_ss7.c:1561 asp-asp-clnt-msc-0: xua_cli_read_cb(): sctp_recvmsg() returned 44 (flags=0x80)
20181109161155174 DLM3UA <0022> git/libosmo-sccp/src/m3ua.c:722 asp-asp-clnt-msc-0: Received M3UA Message (XFER:DATA)
20181109161155174 DLM3UA <0022> git/libosmo-sccp/src/m3ua.c:541 asp-asp-clnt-msc-0: m3ua_rx_xfer
20181109161155174 DLM3UA <0022> git/libosmo-sccp/src/m3ua.c:580 asp-asp-clnt-msc-0: m3ua_rx_xfer(): M3UA data header: opc=185=0.23.1 dpc=187=0.23.3
20181109161155174 DLSS7 <001f> git/libosmo-sccp/src/osmo_ss7_hmrt.c:274 m3ua_hmdc_rx_from_l2(): found dpc=187=0.23.3 as local
20181109161155174 DLSS7 <001f> git/libosmo-sccp/src/sccp_scrc.c:450 scrc_rx_mtp_xfer_ind_xua: HDR=(CO:RELRE,V=0,LEN=0),
PART(T=Destination Reference,L=4,D=00000003),
PART(T=Source Reference,L=4,D=00000002),
PART(T=Cause,L=4,D=00000300)
20181109161155174 DLSCCP <0020> git/libosmo-sccp/src/sccp_scoc.c:1637 Received CO:RELRE for local reference 3
20181109161155174 DLSCCP <0020> git/libosmo-sccp/src/sccp_scoc.c:1670 SCCP-SCOC(3)[0x612000005c20]{ACTIVE}: Received Event RCOC-RELEASED.ind
20181109161155174 DLSCCP <0020> git/libosmo-sccp/src/sccp_user.c:156 Delivering N-DISCONNECT.indication to SCCP User 'msc-0'
20181109161155174 DMSC <0007> git/osmo-bsc/src/osmo-bsc/osmo_bsc_sigtran.c:252 N-DISCONNECT.ind(3, , cause=768)
20181109161155174 DMSC <0007> git/osmo-bsc/src/osmo-bsc/osmo_bsc_sigtran.c:259 SUBSCR_CONN(conn3)[0x612000005920]{CLEARING}: Received Event DISCONNET.ind
20181109161155174 DMSC <0007> git/osmo-bsc/src/osmo-bsc/bsc_subscr_conn_fsm.c:711 SUBSCR_CONN(conn3)[0x612000005920]{CLEARING}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
20181109161155174 DLCLS <000f> git/osmo-bsc/src/osmo-bsc/bsc_subscr_conn_fsm.c:768 LCLS[0x612000005aa0]{NO_LCLS}: Terminating (cause = OSMO_FSM_TERM_REGULAR)
20181109161155174 DLCLS <000f> git/osmo-bsc/src/osmo-bsc/bsc_subscr_conn_fsm.c:768 LCLS[0x612000005aa0]{NO_LCLS}: Removing from parent SUBSCR_CONN(conn3)[0x612000005920]
20181109161155174 DLCLS <000f> git/osmo-bsc/src/osmo-bsc/bsc_subscr_conn_fsm.c:768 LCLS[0x612000005aa0]{NO_LCLS}: Freeing instance
20181109161155174 DLCLS <000f> git/libosmocore/src/fsm.c:381 LCLS[0x612000005aa0]{NO_LCLS}: Deallocated
20181109161155174 DMSC <0007> git/osmo-bsc/src/osmo-bsc/bsc_subscr_conn_fsm.c:768 SUBSCR_CONN(conn3)[0x612000005920]{CLEARING}: Received Event LCLS_FAIL
20181109161155174 DMSC <0007> git/osmo-bsc/src/osmo-bsc/bsc_subscr_conn_fsm.c:772 SUBSCR_CONN(conn3)[0x612000005920]{CLEARING}: Releasing all lchans (if any) because this conn is terminating
20181109161155174 DAS <0012> git/osmo-bsc/src/osmo-bsc/bsc_subscr_conn_fsm.c:711 assignment(conn3_0-0-1-TCH_F-0)[0x612000005da0]{WAIT_RR_ASS_COMPLETE}: Terminating (cause = OSMO_FSM_TERM_PARENT)
20181109161155174 DAS <0012> git/osmo-bsc/src/osmo-bsc/bsc_subscr_conn_fsm.c:711 assignment(conn3_0-0-1-TCH_F-0)[0x612000005da0]{WAIT_RR_ASS_COMPLETE}: Removing from parent SUBSCR_CONN(conn3)[0x612000005920]
20181109161155174 DAS <0012> git/osmo-bsc/src/osmo-bsc/bsc_subscr_conn_fsm.c:711 assignment(conn3_0-0-1-TCH_F-0)[0x612000005da0]{WAIT_RR_ASS_COMPLETE}: Freeing instance
20181109161155174 DAS <0012> git/libosmocore/src/fsm.c:381 assignment(conn3_0-0-1-TCH_F-0)[0x612000005da0]{WAIT_RR_ASS_COMPLETE}: Deallocated
20181109161155175 DMSC <0007> git/osmo-bsc/src/osmo-bsc/bsc_subscr_conn_fsm.c:711 SUBSCR_CONN(conn3)[0x612000005920]{CLEARING}: Freeing instance
20181109161155175 DMSC <0007> git/libosmocore/src/fsm.c:381 SUBSCR_CONN(conn3)[0x612000005920]{CLEARING}: Deallocated
20181109161155175 DLSS7 <001f> git/libosmo-sccp/src/sccp_scrc.c:398 sccp_scrc_rx_scoc_conn_msg: HDR=(CO:RELCO,V=0,LEN=0),
PART(T=Routing Context,L=4,D=00000000),
PART(T=Destination Reference,L=4,D=00000002),
PART(T=Source Reference,L=4,D=00000003)
20181109161155175 DLSS7 <001f> git/libosmo-sccp/src/osmo_ss7_hmrt.c:278 m3ua_hmdc_rx_from_l2(): dpc=185=0.23.1 not local, message is for routing
20181109161155175 DLSS7 <001f> git/libosmo-sccp/src/osmo_ss7_hmrt.c:227 Found route for dpc=185=0.23.1: pc=0=0.0.0 mask=0x0=0.0.0 via AS as-clnt-msc-0 proto=m3ua
20181109161155175 DLSS7 <001f> git/libosmo-sccp/src/osmo_ss7_hmrt.c:233 rt->dest.as proto is M3UA for dpc=185=0.23.1
20181109161155175 DLSS7 <001f> git/libosmo-sccp/src/m3ua.c:507 XUA_AS(as-clnt-msc-0)[0x612000003820]{AS_ACTIVE}: Received Event AS-TRANSFER.req
20181109161155175 DLSCCP <0020> git/libosmo-sccp/src/sccp_scoc.c:1061 SCCP-SCOC(3)[0x612000005c20]{ACTIVE}: state_chg to IDLE
20181109161155175 DLSCCP <0020> git/libosmo-sccp/src/sccp_scoc.c:509 SCCP-SCOC(3)[0x612000005c20]{IDLE}: Terminating (cause = OSMO_FSM_TERM_REQUEST)
20181109161155175 DLSCCP <0020> git/libosmo-sccp/src/sccp_scoc.c:509 SCCP-SCOC(3)[0x612000005c20]{IDLE}: Freeing instance
20181109161155175 DLSCCP <0020> git/libosmocore/src/fsm.c:381 SCCP-SCOC(3)[0x612000005c20]{IDLE}: Deallocated
20181109161155175 DLINP <0015> git/libosmo-netif/src/stream.c:279 connected write
20181109161155175 DLINP <0015> git/libosmo-netif/src/stream.c:204 sending data
20181109161155175 DLINP <0015> git/libosmo-netif/src/stream.c:279 connected write
20181109161155175 DLINP <0015> git/libosmo-netif/src/stream.c:204 sending data
20181109161155189 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 08 33 01 09
20181109161155189 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1129 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_RF_RELEASE_ACK}: (type=TCH_F) Rx RF_CHAN_REL_ACK
20181109161155189 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1161 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_RF_RELEASE_ACK}: Received Event LCHAN_EV_RSL_RF_CHAN_REL_ACK
20181109161155189 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:1024 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_RF_RELEASE_ACK}: state_chg to WAIT_AFTER_ERROR
20181109161155365 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 08 28 01 20 1b 04 19 03 3f 3f 00 04 00 0a 70 08 0b 00 12 06 15 bf 3f 00 00 00 00 00 00 00 00 00 00 00 00 00 00 25 48
20181109161155365 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1129 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_BEFORE_RF_RELEASE}: (type=SDCCH) Rx MEAS_RES
20181109161155365 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:993 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_BEFORE_RF_RELEASE}: (type=SDCCH) MEAS RES for inactive channel
20181109161155416 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 10 19 15 0e 28 80 30 80 38 80 0a 80 0b 80 0c 80 0d 80
20181109161155838 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 08 28 01 20 1b 05 19 03 05 05 3f 04 00 25 3f
20181109161155838 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1129 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_BEFORE_RF_RELEASE}: (type=SDCCH) Rx MEAS_RES
20181109161155838 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:993 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_BEFORE_RF_RELEASE}: (type=SDCCH) MEAS RES for inactive channel
20181109161156307 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 08 28 01 20 1b 06 19 03 03 03 3f 04 00 25 3f
20181109161156307 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1129 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_BEFORE_RF_RELEASE}: (type=SDCCH) Rx MEAS_RES
20181109161156307 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:993 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_BEFORE_RF_RELEASE}: (type=SDCCH) MEAS RES for inactive channel
20181109161156485 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 02 06 01 20 02 00
20181109161156485 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1614 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_BEFORE_RF_RELEASE}: (type=SDCCH) SAPI=0 ESTABLISH INDICATION
20181109161156485 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1647 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_BEFORE_RF_RELEASE}: Received Event LCHAN_EV_RLL_ESTABLISH_IND
20181109161156485 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1647 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_BEFORE_RF_RELEASE}: Event LCHAN_EV_RLL_ESTABLISH_IND not permitted
20181109161156567 DHODEC <0009> git/osmo-bsc/src/osmo-bsc/handover_decision_2.c:1847 (BTS 0) No congestion check: Assignment and Handover both disabled
20181109161156567 DHODEC <0009> git/osmo-bsc/src/osmo-bsc/handover_decision_2.c:162 HO algorithm 2: next periodical congestion check in 10 seconds
20181109161156575 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 02 02 01 20 02 00 0b 00 03 06 2f 6f
20181109161156575 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1605 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_BEFORE_RF_RELEASE}: (type=SDCCH) SAPI=0 DATA INDICATION
20181109161156575 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/gsm_04_08_rr.c:933 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_BEFORE_RF_RELEASE}: (type=SDCCH) Got data in non active state, discarding.
20181109161156575 DLINP <0015> git/libosmo-abis/src/input/ipaccess.c:287 Bad signalling message, sign_link returned error: Operation not permitted.
20181109161156778 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 08 28 01 20 1b 07 19 03 3f 3f 00 04 00 0a 70 08 0b 00 12 06 15 bf 7f 7e 00 00 00 00 00 00 00 00 00 00 00 00 00 25 39
20181109161156778 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1129 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_BEFORE_RF_RELEASE}: (type=SDCCH) Rx MEAS_RES
20181109161156778 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:993 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_BEFORE_RF_RELEASE}: (type=SDCCH) MEAS RES for inactive channel
20181109161156810 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 02 02 01 20 02 00 0b 00 02 03 aa
20181109161156810 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1605 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_BEFORE_RF_RELEASE}: (type=SDCCH) SAPI=0 DATA INDICATION
20181109161156810 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/gsm_04_08_rr.c:933 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_BEFORE_RF_RELEASE}: (type=SDCCH) Got data in non active state, discarding.
20181109161156810 DLINP <0015> git/libosmo-abis/src/input/ipaccess.c:287 Bad signalling message, sign_link returned error: Operation not permitted.
20181109161157170 DCHAN <0010> git/libosmocore/src/fsm.c:189 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_BEFORE_RF_RELEASE}: Timeout of T3111
20181109161157170 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:1278 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_BEFORE_RF_RELEASE}: state_chg to WAIT_RF_RELEASE_ACK
20181109161157170 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:356 TX 2: 08 2e 01 20
20181109161157194 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 08 33 01 20
20181109161157194 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1129 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_RF_RELEASE_ACK}: (type=SDCCH) Rx RF_CHAN_REL_ACK
20181109161157194 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1161 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_RF_RELEASE_ACK}: Received Event LCHAN_EV_RSL_RF_CHAN_REL_ACK
20181109161157194 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:1026 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{WAIT_RF_RELEASE_ACK}: state_chg to UNUSED
20181109161157194 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:371 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{UNUSED}: (type=SDCCH) Clearing lchan state
20181109161157194 DTS <0011> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:404 timeslot(0-0-0-CCCH_SDCCH4)[0x6120000027a0]{IN_USE}: Received Event TS_EV_LCHAN_UNUSED
20181109161157194 DTS <0011> git/osmo-bsc/src/osmo-bsc/timeslot_fsm.c:624 timeslot(0-0-0-CCCH_SDCCH4)[0x6120000027a0]{IN_USE}: state_chg to UNUSED
20181109161157195 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 02 09 01 20 02 00
20181109161157195 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1664 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{UNUSED}: Received Event LCHAN_EV_RLL_REL_IND
20181109161157195 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/abis_rsl.c:1664 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000042a0]{UNUSED}: Event LCHAN_EV_RLL_REL_IND not permitted
20181109161158267 DLMI <0017> git/libosmo-abis/src/input/ipaccess.c:251 RX 2: 10 19 15 10 28 80 30 80 38 80 09 20 0a 80 0b 80 0c 80 0d 80
20181109161159190 DCHAN <0010> git/libosmocore/src/fsm.c:189 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_AFTER_ERROR}: Timeout of T993111
20181109161159190 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:1282 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{WAIT_AFTER_ERROR}: state_chg to UNUSED
20181109161159190 DCHAN <0010> git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:371 lchan(0-0-1-TCH_F-0)[0x6120000048a0]{UNUSED}: (type=TCH_F) Clearing lchan state
=================================================================
==21585==ERROR: AddressSanitizer: heap-use-after-free on address 0x6220000031c0 at pc 0x555555b8fb4c bp 0x7fffffffda50 sp 0x7fffffffda40
READ of size 8 at 0x6220000031c0 thread T0
#0 0x555555b8fb4b in gscon_forget_lchan git/osmo-bsc/src/osmo-bsc/bsc_subscr_conn_fsm.c:656
#1 0x555555cb98d2 in lchan_reset git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:374
#2 0x555555cba162 in lchan_fsm_unused_onenter git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:403
#3 0x7ffff61fc1a5 in state_chg git/libosmocore/src/fsm.c:468
#4 0x7ffff61fc207 in _osmo_fsm_inst_state_chg git/libosmocore/src/fsm.c:501
#5 0x555555c28068 in _fsm_inst_state_chg_T git/osmo-bsc/src/osmo-bsc/gsm_timers.c:189
#6 0x555555ce317d in lchan_fsm_timer_cb git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:1282
#7 0x7ffff61f779c in fsm_tmr_cb git/libosmocore/src/fsm.c:192
#8 0x7ffff61dbef6 in osmo_timers_update git/libosmocore/src/timer.c:257
#9 0x7ffff61df914 in osmo_select_main git/libosmocore/src/select.c:254
#10 0x555555d5d481 in main git/osmo-bsc/src/osmo-bsc/osmo_bsc_main.c:929
#11 0x7ffff5224222 in __libc_start_main (/usr/lib/libc.so.6+0x24222)
#12 0x555555ac181d in _start (/home/pespin/dev/sysmocom/build/new/out/bin/osmo-bsc+0x56d81d)
0x6220000031c0 is located 192 bytes inside of 5056-byte region [0x622000003100,0x6220000044c0)
freed by thread T0 here:
#0 0x7ffff72eac19 in __interceptor_free /build/gcc/src/gcc/libsanitizer/asan/asan_malloc_linux.cc:66
#1 0x7ffff5ef4593 in _talloc_free (/usr/lib/libtalloc.so.2+0x5593)
previously allocated by thread T0 here:
#0 0x7ffff72eb019 in __interceptor_malloc /build/gcc/src/gcc/libsanitizer/asan/asan_malloc_linux.cc:86
#1 0x7ffff5ef7241 in _talloc_zero (/usr/lib/libtalloc.so.2+0x8241)
SUMMARY: AddressSanitizer: heap-use-after-free git/osmo-bsc/src/osmo-bsc/bsc_subscr_conn_fsm.c:656 in gscon_forget_lchan
Shadow bytes around the buggy address:
0x0c447fff85e0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c447fff85f0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c447fff8600: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c447fff8610: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c447fff8620: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
=>0x0c447fff8630: fd fd fd fd fd fd fd fd[fd]fd fd fd fd fd fd fd
0x0c447fff8640: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c447fff8650: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c447fff8660: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c447fff8670: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c447fff8680: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
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
==21585==ABORTING
Program received signal SIGABRT, Aborted.
0x00007ffff5237d7f in raise () from /usr/lib/libc.so.6
Updated by pespin over 5 years ago
bt full after ASan sent abort():
(gdb) bt full
#0 0x00007ffff5237d7f in raise () from /usr/lib/libc.so.6
No symbol table info available.
#1 0x00007ffff5222672 in abort () from /usr/lib/libc.so.6
No symbol table info available.
#2 0x00007ffff730b314 in __sanitizer::Abort ()
at /build/gcc/src/gcc/libsanitizer/sanitizer_common/sanitizer_posix_libcdep.cc:145
No locals.
#3 0x00007ffff7313f8d in __sanitizer::Die ()
at /build/gcc/src/gcc/libsanitizer/sanitizer_common/sanitizer_termination.cc:57
No locals.
#4 0x00007ffff72f659e in __asan::ScopedInErrorReport::~ScopedInErrorReport (
this=<optimized out>, __in_chrg=<optimized out>)
at /build/gcc/src/gcc/libsanitizer/asan/asan_report.cc:181
buffer_copy = <optimized out>
#5 __asan::ReportGenericError (pc=<optimized out>,
bp=bp@entry=140737488345680, sp=sp@entry=140737488345664,
addr=107889578488256, is_write=is_write@entry=false,
access_size=access_size@entry=8, exp=0, fatal=true)
at /build/gcc/src/gcc/libsanitizer/asan/asan_report.cc:397
in_report = {error_report_lock_ = {<No data fields>},
static current_error_ = {kind = __asan::kErrorKindGeneric, {Base = {
--Type <RET> for more, q to quit, c to continue without paging--
scariness = {score = 51,
descr = "8-byte-read-heap-use-after-free\000\377\177\000\000\342\253.\367\377\177\000\000\000\360\377\377\377\177\000\000\000@r\363\377\177\000\000\060\316\377\377\377\177\000\000\002\000\000\000\000\000\000\000\032\254.\367\377\177\000\000\224E\357\365\377\177\000\000\300Y6\367\377\177\000\000\016\246/\367\377\177\000\000\000@r\363\377\177\000\000GM\"\367\377\177\000\000\000\360\377\377\377\177\000\000\340@r\363\377\177\000\000\200\316\377\377\377\177\000\000\000Bw\nY\320\016D\320\316\377\377\377\177\000\000X\345\060\367\377\177\000\000\020\371y\032\377\177\000\000\200u\314\367\377\177\000\000\220\317\377\377\377\177\000\000\000\000\000\000\000\000\000\000"...}, tid = 0},
DeadlySignal = {<__asan::ErrorBase> = {scariness = {score = 51,
descr = "8-byte-read-heap-use-after-free\000\377\177\000\000\342\253.\367\377\177\000\000\000\360\377\377\377\177\000\000\000@r\363\377\177\000\000\060\316\377\377\377\177\000\000\002\000\000\000\000\000\000\000\032\254.\367\377\177\000\000\224E\357\365\377\177\000\000\300Y6\367\377\177\000\000\016\246/\367\377\177\000\000\000@r\363\377\177\000\000GM\"\367\377\177\000\000\000\360\377\377\377\177\000\000\340@r\363\377\177\000\000\200\316\377\377\377\177\000\000\000Bw\nY\320\016D\320\316\377\377\377\177\000\000X\345\060\367\377\177\000\000\020\371y\032\377\177\000\000\200u\314\367\377\177\000\000\220\317\377\377\377\177\000\000\000\000\000\000\000\000\000\000"...}, tid = 0}, signal = {
siginfo = 0x640000000002, context = 0x6220000031c0,
addr = 0, pc = 0, sp = 7962364151861346305,
bp = 107889578488256, is_memory_access = 192,
--Type <RET> for more, q to quit, c to continue without paging--
write_flag = __sanitizer::SignalContext::UNKNOWN}},
DoubleFree = {<__asan::ErrorBase> = {scariness = {score = 51,
descr = "8-byte-read-heap-use-after-free\000\377\177\000\000\342\253.\367\377\177\000\000\000\360\377\377\377\177\000\000\000@r\363\377\177\000\000\060\316\377\377\377\177\000\000\002\000\000\000\000\000\000\000\032\254.\367\377\177\000\000\224E\357\365\377\177\000\000\300Y6\367\377\177\000\000\016\246/\367\377\177\000\000\000@r\363\377\177\000\000GM\"\367\377\177\000\000\000\360\377\377\377\177\000\000\340@r\363\377\177\000\000\200\316\377\377\377\177\000\000\000Bw\nY\320\016D\320\316\377\377\377\177\000\000X\345\060\367\377\177\000\000\020\371y\032\377\177\000\000\200u\314\367\377\177\000\000\220\317\377\377\377\177\000\000\000\000\000\000\000\000\000\000"...}, tid = 0},
second_free_stack = 0x640000000002, addr_description = {
addr = 107889578488256, alloc_tid = 0, free_tid = 0,
alloc_stack_id = 2080374785, free_stack_id = 1853882370,
chunk_access = {bad_addr = 107889578488256, offset = 192,
chunk_begin = 107889578488064, chunk_size = 5056,
access_type = 2, alloc_type = 1}}},
NewDeleteSizeMismatch = {<__asan::ErrorBase> = {scariness = {
score = 51,
descr = "8-byte-read-heap-use-after-free\000\377\177\000\000\342\253.\367\377\177\000\000\000\360\377\377\377\177\000\000\000@r\363\377\177\000\000\060\316\377\377\377\177\000\000\002\000\000\000\000\000\000\000\032\2--Type <RET> for more, q to quit, c to continue without paging--
246/\367\377\177\000\000\000@r\363\377\177\000\000GM\"\367\377\177\000\000\000\360\377\377\377\177\000\000\340@r\363\377\177\000\000\200\316\377\377\377\177\000\000\000Bw\nY\320\016D\320\316\377\377\377\177\000\000X\345\060\367\377\177\000\000\020\371y\032\377\177\000\000\200u\314\367\377\177\000\000\220\317\377\377\377\177\000\000\000\000\000\000\000\000\000\000"...}, tid = 0}, free_stack = 0x640000000002, addr_description = {addr = 107889578488256, alloc_tid = 0,
free_tid = 0, alloc_stack_id = 2080374785, free_stack_id = 1853882370, chunk_access = {bad_addr = 107889578488256, offset = 192, chunk_begin = 107889578488064, chunk_size = 5056, access_type = 2, alloc_type = 1}},
delete_size = 140737277767312}, FreeNotMalloced = {<__asan::ErrorBase> = {scariness = {score = 51,
descr = "8-byte-read-heap-use-after-free\000\377\177\000\000\342\253.\367\377\177\000\000\000\360\377\377\377\177\000\000\000@r\363\377\177\000\000\060\316\377\377\377\177\000\000\002\000\000\000\000\000\000\000\032\254.\367\377\177\000\000\224E\357\365\377\177\000\000\300Y6\367\377\177\000\000\016\246/\367\377\177\000\000\000@r\363\377\177\000\000GM\"\367\377\177\000\000\000\360\377\377\377\177\000\000\340@r\363\377\177\000\000\200\316\377\377\377\177\000\000\000Bw\nY\320\016D\320\316\377\377\377\177\000\000X\345\060\367\377\177\000\000\020\371y\032\377\177\000\000\200u\314\367\377\177\000\000\220\317\377\377\377\177\000\000\000\000\000\000\000\000\000\000"...}, tid = 0},
free_stack = 0x640000000002, addr_description = {data = {kind = 12736, {shadow = {addr = 0, kind = __asan::kShadowKindLow, shadow_byte = 0 '\000'}, heap = {addr = 0, alloc_tid = 0, free_tid = 7962364151861346305,
alloc_stack_id = 12736, free_stack_id = 25120, chunk_access = {bad_addr = 192, offset = 107889578488064, chunk_begin = 5056, chunk_size = 106450343810310, access_type = 0, alloc_type = 0}}, stack = {addr = 0,
tid = 0, offset = 7962364151861346305, frame_pc = 107889578488256, access_size = 192, frame_descr = 0x622000003100 "\002"}, global = {addr = 0, static kMaxGlobals = 4, globals = {{beg = 0,
size = 7962364151861346305, size_with_redzone = 107889578488256, name = 0xc0 <error: Cannot access memory at address 0xc0>, module_name = 0x622000003100 "\002", has_dynamic_init = 5056,
location = 0x60d0e6edd506, odr_indicator = 140737277767312}, {beg = 36, size = 1568, size_with_redzone = 1435, name = 0x59b <error: Cannot access memory at address 0x59b>,
module_name = 0x620 <error: Cannot access memory at address 0x620>, has_dynamic_init = 27, location = 0xc3600012423, odr_indicator = 1435}, {beg = 140737340922304, size = 140737339595543,
size_with_redzone = 107408542735232, name = 0x61b000091b70 "\003", module_name = 0x61b000091b80 "\002", has_dynamic_init = 7, location = 0x1007fffffffd3a0, odr_indicator = 140737277739008}, {beg = 128,
size = 128, size_with_redzone = 140737277767088, name = 0x440ed0590a774200 <error: Cannot access memory at address 0x440ed0590a774200>, module_name = 0x7fffffffd330 "\b", has_dynamic_init = 140737340564824,
location = 0x7fffe6edd50a, odr_indicator = 140737352783184}}, reg_sites = {4294956016, 32767, 0, 0}, access_size = 1, size = 76 'L'}, addr = 0}}}}, AllocTypeMismatch = {<__asan::ErrorBase> = {scariness = {
score = 51,
descr = "8-byte-read-heap-use-after-free\000\377\177\000\000\342\253.\367\377\177\000\000\000\360\377\377\377\177\000\000\000@r\363\377\177\000\000\060\316\377\377\377\177\000\000\002\000\000\000\000\000\000\000\032\254.\367\377\177\000\000\224E\357\365\377\177\000\000\300Y6\367\377\177\000\000\016\246/\367\377\177\000\000\000@r\363\377\177\000\000GM\"\367\377\177\000\000\000\360\377\377\377\177\000\000\340@r\363\377\177\000\000\200\316\377\377\377\177\000\000\000Bw\nY\320\016D\320\316\377\377\377\177\000\000X\345\060\367\377\177\000\000\020\371y\032\377\177\000\000\200u\314\367\377\177\000\000\220\317\377\377\377\177\000\000\000\000\000\000\000\000\000\000"...}, tid = 0},
dealloc_stack = 0x640000000002, addr_description = {addr = 107889578488256, alloc_tid = 0, free_tid = 0, alloc_stack_id = 2080374785, free_stack_id = 1853882370, chunk_access = {bad_addr = 107889578488256, offset = 192,
chunk_begin = 107889578488064, chunk_size = 5056, access_type = 2, alloc_type = 1}}, alloc_type = 4084379280, dealloc_type = 32767}, MallocUsableSizeNotOwned = {<__asan::ErrorBase> = {scariness = {score = 51,
descr = "8-byte-read-heap-use-after-free\000\377\177\000\000\342\253.\367\377\177\000\000\000\360\377\377\377\177\000\000\000@r\363\377\177\000\000\060\316\377\377\377\177\000\000\002\000\000\000\000\000\000\000\032\254.\367\377\177\000\000\224E\357\365\377\177\000\000\300Y6\367\377\177\000\000\016\246/\367\377\177\000\000\000@r\363\377\177\000\000GM\"\367\377\177\000\000\000\360\377\377\377\177\000\000\340@r\363\377\177\000\000\200\316\377\377\377\177\000\000\000Bw\nY\320\016D\320\316\377\377\377\177\000\000X\345\060\367\377\177\000\000\020\371y\032\377\177\000\000\200u\314\367\377\177\000\000\220\317\377\377\377\177\000\000\000\000\000\000\000\000\000\000"...}, tid = 0},
stack = 0x640000000002, addr_description = {data = {kind = 12736, {shadow = {addr = 0, kind = __asan::kShadowKindLow, shadow_byte = 0 '\000'}, heap = {addr = 0, alloc_tid = 0, free_tid = 7962364151861346305,
alloc_stack_id = 12736, free_stack_id = 25120, chunk_access = {bad_addr = 192, offset = 107889578488064, chunk_begin = 5056, chunk_size = 106450343810310, access_type = 0, alloc_type = 0}}, stack = {addr = 0,
tid = 0, offset = 7962364151861346305, frame_pc = 107889578488256, access_size = 192, frame_descr = 0x622000003100 "\002"}, global = {addr = 0, static kMaxGlobals = 4, globals = {{beg = 0,
size = 7962364151861346305, size_with_redzone = 107889578488256, name = 0xc0 <error: Cannot access memory at address 0xc0>, module_name = 0x622000003100 "\002", has_dynamic_init = 5056,
location = 0x60d0e6edd506, odr_indicator = 140737277767312}, {beg = 36, size = 1568, size_with_redzone = 1435, name = 0x59b <error: Cannot access memory at address 0x59b>,
module_name = 0x620 <error: Cannot access memory at address 0x620>, has_dynamic_init = 27, location = 0xc3600012423, odr_indicator = 1435}, {beg = 140737340922304, size = 140737339595543,
size_with_redzone = 107408542735232, name = 0x61b000091b70 "\003", module_name = 0x61b000091b80 "\002", has_dynamic_init = 7, location = 0x1007fffffffd3a0, odr_indicator = 140737277739008}, {beg = 128,
size = 128, size_with_redzone = 140737277767088, name = 0x440ed0590a774200 <error: Cannot access memory at address 0x440ed0590a774200>, module_name = 0x7fffffffd330 "\b", has_dynamic_init = 140737340564824,
location = 0x7fffe6edd50a, odr_indicator = 140737352783184}}, reg_sites = {4294956016, 32767, 0, 0}, access_size = 1, size = 76 'L'}, addr = 0}}}}, SanitizerGetAllocatedSizeNotOwned = {<__asan::ErrorBase> = {
scariness = {score = 51,
descr = "8-byte-read-heap-use-after-free\000\377\177\000\000\342\253.\367\377\177\000\000\000\360\377\377\377\177\000\000\000@r\363\377\177\000\000\060\316\377\377\377\177\000\000\002\000\000\000\000\000\000\000\032\254.\367\377\177\000\000\224E\357\365\377\177\000\000\300Y6\367\377\177\000\000\016\246/\367\377\177\000\000\000@r\363\377\177\000\000GM\"\367\377\177\000\000\000\360\377\377\377\177\000\000\340@r\363\377\177\000\000\200\316\377\377\377\177\000\000\000Bw\nY\320\016D\320\316\377\377\377\177\000\000X\345\060\367\377\177\000\000\020\371y\032\377\177\000\000\200u\314\367\377\177\000\000\220\317\377\377\377\177\000\000\000\000\000\000\000\000\000\000"...}, tid = 0},
stack = 0x640000000002, addr_description = {data = {kind = 12736, {shadow = {addr = 0, kind = __asan::kShadowKindLow, shadow_byte = 0 '\000'}, heap = {addr = 0, alloc_tid = 0, free_tid = 7962364151861346305,
alloc_stack_id = 12736, free_stack_id = 25120, chunk_access = {bad_addr = 192, offset = 107889578488064, chunk_begin = 5056, chunk_size = 106450343810310, access_type = 0, alloc_type = 0}}, stack = {addr = 0,
tid = 0, offset = 7962364151861346305, frame_pc = 107889578488256, access_size = 192, frame_descr = 0x622000003100 "\002"}, global = {addr = 0, static kMaxGlobals = 4, globals = {{beg = 0,
size = 7962364151861346305, size_with_redzone = 107889578488256, name = 0xc0 <error: Cannot access memory at address 0xc0>, module_name = 0x622000003100 "\002", has_dynamic_init = 5056,
location = 0x60d0e6edd506, odr_indicator = 140737277767312}, {beg = 36, size = 1568, size_with_redzone = 1435, name = 0x59b <error: Cannot access memory at address 0x59b>,
module_name = 0x620 <error: Cannot access memory at address 0x620>, has_dynamic_init = 27, location = 0xc3600012423, odr_indicator = 1435}, {beg = 140737340922304, size = 140737339595543,
size_with_redzone = 107408542735232, name = 0x61b000091b70 "\003", module_name = 0x61b000091b80 "\002", has_dynamic_init = 7, location = 0x1007fffffffd3a0, odr_indicator = 140737277739008}, {beg = 128,
size = 128, size_with_redzone = 140737277767088, name = 0x440ed0590a774200 <error: Cannot access memory at address 0x440ed0590a774200>, module_name = 0x7fffffffd330 "\b", has_dynamic_init = 140737340564824,
location = 0x7fffe6edd50a, odr_indicator = 140737352783184}}, reg_sites = {4294956016, 32767, 0, 0}, access_size = 1, size = 76 'L'}, addr = 0}}}}, StringFunctionMemoryRangesOverlap = {<__asan::ErrorBase> = {
scariness = {score = 51,
descr = "8-byte-read-heap-use-after-free\000\377\177\000\000\342\253.\367\377\177\000\000\000\360\377\377\377\177\000\000\000@r\363\377\177\000\000\060\316\377\377\377\177\000\000\002\000\000\000\000\000\000\000\032\254.\367\377\177\000\000\224E\357\365\377\177\000\000\300Y6\367\377\177\000\000\016\246/\367\377\177\000\000\000@r\363\377\177\000\000GM\"\367\377\177\000\000\000\360\377\377\377\177\000\000\340@r\363\377\177\000\000\200\316\377\377\377\177\000\000\000Bw\nY\320\016D\320\316\377\377\377\177\000\000X\345\060\367\377\177\000\000\020\371y\032\377\177\000\000\200u\314\367\377\177\000\000\220\317\377\377\377\177\000\000\000\000\000\000\000\000\000\000"...}, tid = 0},
stack = 0x640000000002, length1 = 107889578488256, length2 = 0, addr1_description = {data = {kind = __asan::kAddressKindWild, {shadow = {addr = 7962364151861346305, kind = (unknown: -64), shadow_byte = 49 '1'}, heap = {
addr = 7962364151861346305, alloc_tid = 107889578488256, free_tid = 192, alloc_stack_id = 12544, free_stack_id = 25120, chunk_access = {bad_addr = 5056, offset = 106450343810310, chunk_begin = 140737277767312,
chunk_size = 36, access_type = 0, alloc_type = 0}}, stack = {addr = 7962364151861346305, tid = 107889578488256, offset = 192, frame_pc = 107889578488064, access_size = 5056, frame_descr = 0x60d0e6edd506 ""},
global = {addr = 7962364151861346305, static kMaxGlobals = 4, globals = {{beg = 107889578488256, size = 192, size_with_redzone = 107889578488064, name = 0x13c0 <error: Cannot access memory at address 0x13c0>,
module_name = 0x60d0e6edd506 "", has_dynamic_init = 140737277767312, location = 0x24, odr_indicator = 1568}, {beg = 1435, size = 1435, size_with_redzone = 1568,
name = 0x1b <error: Cannot access memory at address 0x1b>, module_name = 0xc3600012423 "", has_dynamic_init = 1435, location = 0x7ffff73659c0 <__asan::instance>, odr_indicator = 140737339595543}, {
beg = 107408542735232, size = 107408542735216, size_with_redzone = 107408542735232, name = 0x7 <error: Cannot access memory at address 0x7>,
module_name = 0x1007fffffffd3a0 <error: Cannot access memory at address 0x1007fffffffd3a0>, has_dynamic_init = 140737277739008, location = 0x80, odr_indicator = 128}, {beg = 140737277767088,
size = 4904086125099303424, size_with_redzone = 140737488343856,
name = 0x7ffff730e558 <__sanitizer::StackDepotBase<__sanitizer::StackDepotNode, 1, 20>::Put(__sanitizer::StackTrace, bool*)+216> "D\213\004$H\205\300uQH\213|$\bD\211\004$\350\241\376\377\377D\213\004$I9\305H\211D$ tKH\213t$\020D\211\301H\211\332H\211\307I\211\305\350\r\376\377\377D\213\004$H\205\300t,H\213\\$\bL\211+\353\ff.\017\037\204", module_name = 0x7fffe6edd50a <error: Cannot access memory at address 0x7fffe6edd50a>,
has_dynamic_init = 140737352783184, location = 0x7fffffffd3f0, odr_indicator = 0}}, reg_sites = {1, 0, 1438186316, 21845}, access_size = 140737488345680, size = 64 '@'}, addr = 7962364151861346305}}},
addr2_description = {data = {kind = 8, {shadow = {addr = 140737340695492, kind = __asan::kShadowKindLow, shadow_byte = 253 '\375'}, heap = {addr = 140737340695492, alloc_tid = 107408542792960, free_tid = 2,
alloc_stack_id = 14, free_stack_id = 2147483648, chunk_access = {bad_addr = 0, offset = 0, chunk_begin = 0, chunk_size = 0, access_type = 0, alloc_type = 0}}, stack = {addr = 140737340695492,
--Type <RET> for more, q to quit, c to continue without paging--
tid = 107408542792960, offset = 2, frame_pc = 9223372036854775822, access_size = 0, frame_descr = 0x0}, global = {addr = 140737340695492, static kMaxGlobals = 4, globals = {{beg = 107408542792960, size = 2,
size_with_redzone = 9223372036854775822, name = 0x0, module_name = 0x0, has_dynamic_init = 0, location = 0x0, odr_indicator = 0}, {beg = 0, size = 140737488345424, size_with_redzone = 140737323184640,
name = 0x555555eb4da0 "%s{%s}: (type=%s) Clearing lchan state\n", module_name = 0x17300000000 "", has_dynamic_init = 93825002059328, location = 0x1000000001, odr_indicator = 1102416563}, {
beg = 140737323184654, size = 140737322739724, size_with_redzone = 106790066847904, name = 0x3000000030 "", module_name = 0x7fffffffda70 "p\363\002", has_dynamic_init = 140737488345488,
location = 0xffffffffb38, odr_indicator = 140737488345536}, {beg = 93825002072320, size = 140737488345840, size_with_redzone = 4904086125099303424, name = 0x7fffffffd9e0 "0",
module_name = 0x7ffff62f7860 <osmo_log_target_list> "\240", has_dynamic_init = 140737323157088, location = 0x50200000000, odr_indicator = 93825002059328}}, reg_sites = {1, 16, 1102416563, 0},
access_size = 140737323184654, size = 12 '\f'}, addr = 140737340695492}}}, function = 0x7fffffffdbc8 "\025\036\"\366\002\005"}, StringFunctionSizeOverflow = {<__asan::ErrorBase> = {scariness = {score = 51,
descr = "8-byte-read-heap-use-after-free\000\377\177\000\000\342\253.\367\377\177\000\000\000\360\377\377\377\177\000\000\000@r\363\377\177\000\000\060\316\377\377\377\177\000\000\002\000\000\000\000\000\000\000\032\254.\367\377\177\000\000\224E\357\365\377\177\000\000\300Y6\367\377\177\000\000\016\246/\367\377\177\000\000\000@r\363\377\177\000\000GM\"\367\377\177\000\000\000\360\377\377\377\177\000\000\340@r\363\377\177\000\000\200\316\377\377\377\177\000\000\000Bw\nY\320\016D\320\316\377\377\377\177\000\000X\345\060\367\377\177\000\000\020\371y\032\377\177\000\000\200u\314\367\377\177\000\000\220\317\377\377\377\177\000\000\000\000\000\000\000\000\000\000"...}, tid = 0},
stack = 0x640000000002, addr_description = {data = {kind = 12736, {shadow = {addr = 0, kind = __asan::kShadowKindLow, shadow_byte = 0 '\000'}, heap = {addr = 0, alloc_tid = 0, free_tid = 7962364151861346305,
alloc_stack_id = 12736, free_stack_id = 25120, chunk_access = {bad_addr = 192, offset = 107889578488064, chunk_begin = 5056, chunk_size = 106450343810310, access_type = 0, alloc_type = 0}}, stack = {addr = 0,
tid = 0, offset = 7962364151861346305, frame_pc = 107889578488256, access_size = 192, frame_descr = 0x622000003100 "\002"}, global = {addr = 0, static kMaxGlobals = 4, globals = {{beg = 0,
size = 7962364151861346305, size_with_redzone = 107889578488256, name = 0xc0 <error: Cannot access memory at address 0xc0>, module_name = 0x622000003100 "\002", has_dynamic_init = 5056,
location = 0x60d0e6edd506, odr_indicator = 140737277767312}, {beg = 36, size = 1568, size_with_redzone = 1435, name = 0x59b <error: Cannot access memory at address 0x59b>,
module_name = 0x620 <error: Cannot access memory at address 0x620>, has_dynamic_init = 27, location = 0xc3600012423, odr_indicator = 1435}, {beg = 140737340922304, size = 140737339595543,
size_with_redzone = 107408542735232, name = 0x61b000091b70 "\003", module_name = 0x61b000091b80 "\002", has_dynamic_init = 7, location = 0x1007fffffffd3a0, odr_indicator = 140737277739008}, {beg = 128,
size = 128, size_with_redzone = 140737277767088, name = 0x440ed0590a774200 <error: Cannot access memory at address 0x440ed0590a774200>, module_name = 0x7fffffffd330 "\b", has_dynamic_init = 140737340564824,
location = 0x7fffe6edd50a, odr_indicator = 140737352783184}}, reg_sites = {4294956016, 32767, 0, 0}, access_size = 1, size = 76 'L'}, addr = 0}}}, size = 140737488345680},
BadParamsToAnnotateContiguousContainer = {<__asan::ErrorBase> = {scariness = {score = 51,
descr = "8-byte-read-heap-use-after-free\000\377\177\000\000\342\253.\367\377\177\000\000\000\360\377\377\377\177\000\000\000@r\363\377\177\000\000\060\316\377\377\377\177\000\000\002\000\000\000\000\000\000\000\032\254.\367\377\177\000\000\224E\357\365\377\177\000\000\300Y6\367\377\177\000\000\016\246/\367\377\177\000\000\000@r\363\377\177\000\000GM\"\367\377\177\000\000\000\360\377\377\377\177\000\000\340@r\363\377\177\000\000\200\316\377\377\377\177\000\000\000Bw\nY\320\016D\320\316\377\377\377\177\000\000X\345\060\367\377\177\000\000\020\371y\032\377\177\000\000\200u\314\367\377\177\000\000\220\317\377\377\377\177\000\000\000\000\000\000\000\000\000\000"...}, tid = 0},
stack = 0x640000000002, beg = 107889578488256, end = 0, old_mid = 0, new_mid = 7962364151861346305}, ODRViolation = {<__asan::ErrorBase> = {scariness = {score = 51,
descr = "8-byte-read-heap-use-after-free\000\377\177\000\000\342\253.\367\377\177\000\000\000\360\377\377\377\177\000\000\000@r\363\377\177\000\000\060\316\377\377\377\177\000\000\002\000\000\000\000\000\000\000\032\254.\367\377\177\000\000\224E\357\365\377\177\000\000\300Y6\367\377\177\000\000\016\246/\367\377\177\000\000\000@r\363\377\177\000\000GM\"\367\377\177\000\000\000\360\377\377\377\177\000\000\340@r\363\377\177\000\000\200\316\377\377\377\177\000\000\000Bw\nY\320\016D\320\316\377\377\377\177\000\000X\345\060\367\377\177\000\000\020\371y\032\377\177\000\000\200u\314\367\377\177\000\000\220\317\377\377\377\177\000\000\000\000\000\000\000\000\000\000"...}, tid = 0},
global1 = {beg = 109951162777602, size = 107889578488256, size_with_redzone = 0, name = 0x0, module_name = 0x6e8000027c000001 <error: Cannot access memory at address 0x6e8000027c000001>,
has_dynamic_init = 107889578488256, location = 0xc0, odr_indicator = 107889578488064}, global2 = {beg = 5056, size = 106450343810310, size_with_redzone = 140737277767312,
name = 0x24 <error: Cannot access memory at address 0x24>, module_name = 0x620 <error: Cannot access memory at address 0x620>, has_dynamic_init = 1435, location = 0x59b, odr_indicator = 1568}, stack_id1 = 27,
stack_id2 = 0}, InvalidPointerPair = {<__asan::ErrorBase> = {scariness = {score = 51,
descr = "8-byte-read-heap-use-after-free\000\377\177\000\000\342\253.\367\377\177\000\000\000\360\377\377\377\177\000\000\000@r\363\377\177\000\000\060\316\377\377\377\177\000\000\002\000\000\000\000\000\000\000\032\254.\367\377\177\000\000\224E\357\365\377\177\000\000\300Y6\367\377\177\000\000\016\246/\367\377\177\000\000\000@r\363\377\177\000\000GM\"\367\377\177\000\000\000\360\377\377\377\177\000\000\340@r\363\377\177\000\000\200\316\377\377\377\177\000\000\000Bw\nY\320\016D\320\316\377\377\377\177\000\000X\345\060\367\377\177\000\000\020\371y\032\377\177\000\000\200u\314\367\377\177\000\000\220\317\377\377\377\177\000\000\000\000\000\000\000\000\000\000"...}, tid = 0},
pc = 109951162777602, bp = 107889578488256, sp = 0, addr1_description = {data = {kind = __asan::kAddressKindWild, {shadow = {addr = 7962364151861346305, kind = (unknown: -64), shadow_byte = 49 '1'}, heap = {
addr = 7962364151861346305, alloc_tid = 107889578488256, free_tid = 192, alloc_stack_id = 12544, free_stack_id = 25120, chunk_access = {bad_addr = 5056, offset = 106450343810310, chunk_begin = 140737277767312,
chunk_size = 36, access_type = 0, alloc_type = 0}}, stack = {addr = 7962364151861346305, tid = 107889578488256, offset = 192, frame_pc = 107889578488064, access_size = 5056, frame_descr = 0x60d0e6edd506 ""},
global = {addr = 7962364151861346305, static kMaxGlobals = 4, globals = {{beg = 107889578488256, size = 192, size_with_redzone = 107889578488064, name = 0x13c0 <error: Cannot access memory at address 0x13c0>,
module_name = 0x60d0e6edd506 "", has_dynamic_init = 140737277767312, location = 0x24, odr_indicator = 1568}, {beg = 1435, size = 1435, size_with_redzone = 1568,
name = 0x1b <error: Cannot access memory at address 0x1b>, module_name = 0xc3600012423 "", has_dynamic_init = 1435, location = 0x7ffff73659c0 <__asan::instance>, odr_indicator = 140737339595543}, {
beg = 107408542735232, size = 107408542735216, size_with_redzone = 107408542735232, name = 0x7 <error: Cannot access memory at address 0x7>,
module_name = 0x1007fffffffd3a0 <error: Cannot access memory at address 0x1007fffffffd3a0>, has_dynamic_init = 140737277739008, location = 0x80, odr_indicator = 128}, {beg = 140737277767088,
size = 4904086125099303424, size_with_redzone = 140737488343856,
name = 0x7ffff730e558 <__sanitizer::StackDepotBase<__sanitizer::StackDepotNode, 1, 20>::Put(__sanitizer::StackTrace, bool*)+216> "D\213\004$H\205\300uQH\213|$\bD\211\004$\350\241\376\377\377D\213\004$I9\305H\211D$ tKH\213t$\020D\211\301H\211\332H\211\307I\211\305\350\r\376\377\377D\213\004$H\205\300t,H\213\\$\bL\211+\353\ff.\017\037\204", module_name = 0x7fffe6edd50a <error: Cannot access memory at address 0x7fffe6edd50a>,
has_dynamic_init = 140737352783184, location = 0x7fffffffd3f0, odr_indicator = 0}}, reg_sites = {1, 0, 1438186316, 21845}, access_size = 140737488345680, size = 64 '@'}, addr = 7962364151861346305}}},
addr2_description = {data = {kind = 8, {shadow = {addr = 140737340695492, kind = __asan::kShadowKindLow, shadow_byte = 253 '\375'}, heap = {addr = 140737340695492, alloc_tid = 107408542792960, free_tid = 2,
alloc_stack_id = 14, free_stack_id = 2147483648, chunk_access = {bad_addr = 0, offset = 0, chunk_begin = 0, chunk_size = 0, access_type = 0, alloc_type = 0}}, stack = {addr = 140737340695492,
tid = 107408542792960, offset = 2, frame_pc = 9223372036854775822, access_size = 0, frame_descr = 0x0}, global = {addr = 140737340695492, static kMaxGlobals = 4, globals = {{beg = 107408542792960, size = 2,
size_with_redzone = 9223372036854775822, name = 0x0, module_name = 0x0, has_dynamic_init = 0, location = 0x0, odr_indicator = 0}, {beg = 0, size = 140737488345424, size_with_redzone = 140737323184640,
name = 0x555555eb4da0 "%s{%s}: (type=%s) Clearing lchan state\n", module_name = 0x17300000000 "", has_dynamic_init = 93825002059328, location = 0x1000000001, odr_indicator = 1102416563}, {
beg = 140737323184654, size = 140737322739724, size_with_redzone = 106790066847904, name = 0x3000000030 "", module_name = 0x7fffffffda70 "p\363\002", has_dynamic_init = 140737488345488,
location = 0xffffffffb38, odr_indicator = 140737488345536}, {beg = 93825002072320, size = 140737488345840, size_with_redzone = 4904086125099303424, name = 0x7fffffffd9e0 "0",
module_name = 0x7ffff62f7860 <osmo_log_target_list> "\240", has_dynamic_init = 140737323157088, location = 0x50200000000, odr_indicator = 93825002059328}}, reg_sites = {1, 16, 1102416563, 0},
access_size = 140737323184654, size = 12 '\f'}, addr = 140737340695492}}}}, Generic = {<__asan::ErrorBase> = {scariness = {score = 51,
descr = "8-byte-read-heap-use-after-free\000\377\177\000\000\342\253.\367\377\177\000\000\000\360\377\377\377\177\000\000\000@r\363\377\177\000\000\060\316\377\377\377\177\000\000\002\000\000\000\000\000\000\000\032\254.\367\377\177\000\000\224E\357\365\377\177\000\000\300Y6\367\377\177\000\000\016\246/\367\377\177\000\000\000@r\363\377\177\000\000GM\"\367\377\177\000\000\000\360\377\377\377\177\000\000\340@r\363\377\177\000\000\200\316\377\377\377\177\000\000\000Bw\nY\320\016D\320\316\377\377\377\177\000\000X\345\060\367\377\177\000\000\020\371y\032\377\177\000\000\200u\314\367\377\177\000\000\220\317\377\377\377\177\000\000\000\000\000\000\000\000\000\000"...}, tid = 0},
addr_description = {data = {kind = __asan::kAddressKindHeap, {shadow = {addr = 107889578488256, kind = __asan::kShadowKindLow, shadow_byte = 0 '\000'}, heap = {addr = 107889578488256, alloc_tid = 0, free_tid = 0,
alloc_stack_id = 2080374785, free_stack_id = 1853882370, chunk_access = {bad_addr = 107889578488256, offset = 192, chunk_begin = 107889578488064, chunk_size = 5056, access_type = 2, alloc_type = 1}}, stack = {
addr = 107889578488256, tid = 0, offset = 0, frame_pc = 7962364151861346305, access_size = 107889578488256, frame_descr = 0xc0 <error: Cannot access memory at address 0xc0>}, global = {addr = 107889578488256,
static kMaxGlobals = 4, globals = {{beg = 0, size = 0, size_with_redzone = 7962364151861346305, name = 0x6220000031c0 "", module_name = 0xc0 <error: Cannot access memory at address 0xc0>,
has_dynamic_init = 107889578488064, location = 0x13c0, odr_indicator = 106450343810310}, {beg = 140737277767312, size = 36, size_with_redzone = 1568,
name = 0x59b <error: Cannot access memory at address 0x59b>, module_name = 0x59b <error: Cannot access memory at address 0x59b>, has_dynamic_init = 1568, location = 0x1b, odr_indicator = 13426067842083}, {
beg = 1435, size = 140737340922304, size_with_redzone = 140737339595543, name = 0x61b000091b80 "\002", module_name = 0x61b000091b70 "\003", has_dynamic_init = 107408542735232, location = 0x7,
--Type <RET> for more, q to quit, c to continue without paging--
odr_indicator = 72198331526271904}, {beg = 140737277739008, size = 128, size_with_redzone = 128, name = 0x7ffff372adb0 "",
module_name = 0x440ed0590a774200 <error: Cannot access memory at address 0x440ed0590a774200>, has_dynamic_init = 140737488343856,
location = 0x7ffff730e558 <__sanitizer::StackDepotBase<__sanitizer::StackDepotNode, 1, 20>::Put(__sanitizer::StackTrace, bool*)+216>, odr_indicator = 140737067734282}}, reg_sites = {4159395152, 32767,
4294956016, 32767}, access_size = 0, size = 1 '\001'}, addr = 107889578488256}}}, pc = 93824998767436, bp = 140737488345680, sp = 140737488345664, access_size = 8,
bug_descr = 0x7ffff732e3c4 "heap-use-after-free", is_write = false, shadow_val = 253 '\375'}}}, halt_on_error_ = true}
error = {<__asan::ErrorBase> = {scariness = {score = 51,
descr = "8-byte-read-heap-use-after-free\000\377\177\000\000\342\253.\367\377\177\000\000\000\360\377\377\377\177\000\000\000@r\363\377\177\000\000\060\316\377\377\377\177\000\000\002\000\000\000\000\000\000\000\032\254.\367\377\177\000\000\224E\357\365\377\177\000\000\300Y6\367\377\177\000\000\016\246/\367\377\177\000\000\000@r\363\377\177\000\000GM\"\367\377\177\000\000\000\360\377\377\377\177\000\000\340@r\363\377\177\000\000\200\316\377\377\377\177\000\000\000Bw\nY\320\016D\320\316\377\377\377\177\000\000X\345\060\367\377\177\000\000\020\371y\032\377\177\000\000\200u\314\367\377\177\000\000\220\317\377\377\377\177\000\000\000\000\000\000\000\000\000\000"...}, tid = 0},
addr_description = {data = {kind = __asan::kAddressKindHeap, {shadow = {addr = 107889578488256, kind = __asan::kShadowKindLow, shadow_byte = 0 '\000'}, heap = {addr = 107889578488256, alloc_tid = 0, free_tid = 0,
alloc_stack_id = 2080374785, free_stack_id = 1853882370, chunk_access = {bad_addr = 107889578488256, offset = 192, chunk_begin = 107889578488064, chunk_size = 5056, access_type = 2, alloc_type = 1}}, stack = {
addr = 107889578488256, tid = 0, offset = 0, frame_pc = 7962364151861346305, access_size = 107889578488256, frame_descr = 0xc0 <error: Cannot access memory at address 0xc0>}, global = {addr = 107889578488256,
static kMaxGlobals = 4, globals = {{beg = 0, size = 0, size_with_redzone = 7962364151861346305, name = 0x6220000031c0 "", module_name = 0xc0 <error: Cannot access memory at address 0xc0>,
has_dynamic_init = 107889578488064, location = 0x13c0, odr_indicator = 106450343810310}, {beg = 140737277767312, size = 36, size_with_redzone = 1568, name = 0x59b <error: Cannot access memory at address 0x59b>,
module_name = 0x59b <error: Cannot access memory at address 0x59b>, has_dynamic_init = 1568, location = 0x1b, odr_indicator = 13426067842083}, {beg = 1435, size = 140737340922304,
size_with_redzone = 140737339595543, name = 0x61b000091b80 "\002", module_name = 0x61b000091b70 "\003", has_dynamic_init = 107408542735232, location = 0x7, odr_indicator = 72198331526271904}, {
beg = 140737277739008, size = 128, size_with_redzone = 128, name = 0x7ffff372adb0 "", module_name = 0x440ed0590a774200 <error: Cannot access memory at address 0x440ed0590a774200>,
has_dynamic_init = 140737488343856, location = 0x7ffff730e558 <__sanitizer::StackDepotBase<__sanitizer::StackDepotNode, 1, 20>::Put(__sanitizer::StackTrace, bool*)+216>, odr_indicator = 140737067734282}},
reg_sites = {4159395152, 32767, 4294956016, 32767}, access_size = 0, size = 1 '\001'}, addr = 107889578488256}}}, pc = 93824998767436, bp = 140737488345680, sp = 140737488345664, access_size = 8,
bug_descr = 0x7ffff732e3c4 "heap-use-after-free", is_write = false, shadow_val = 253 '\375'}
#6 0x00007ffff72f70bc in __asan::__asan_report_load8 (addr=<optimized out>) at /build/gcc/src/gcc/libsanitizer/asan/asan_rtl.cc:112
bp = 140737488345680
pc = <optimized out>
local_stack = 93825006939264
sp = 140737488345664
#7 0x0000555555b8fb4c in gscon_forget_lchan (conn=0x622000003160, lchan=0x7ffff1255cf8) at git/osmo-bsc/src/osmo-bsc/bsc_subscr_conn_fsm.c:656
No locals.
#8 0x0000555555cb98d3 in lchan_reset (lchan=0x7ffff1255cf8) at git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:374
No locals.
#9 0x0000555555cba163 in lchan_fsm_unused_onenter (fi=0x6120000048a0, prev_state=9) at git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:403
lchan = 0x7ffff1255cf8
#10 0x00007ffff61fc1a6 in state_chg (fi=0x6120000048a0, new_state=0, keep_timer=false, timeout_secs=0, T=0, file=0x555555eb3640 "git/osmo-bsc/src/osmo-bsc/lchan_fsm.c", line=1282)
at git/libosmocore/src/fsm.c:468
fsm = 0x55555635ac80 <lchan_fsm>
old_state = 9
st = 0x555555f68640 <lchan_fsm_states>
#11 0x00007ffff61fc208 in _osmo_fsm_inst_state_chg (fi=0x6120000048a0, new_state=0, timeout_secs=0, T=0, file=0x555555eb3640 "git/osmo-bsc/src/osmo-bsc/lchan_fsm.c", line=1282)
at git/libosmocore/src/fsm.c:501
No locals.
#12 0x0000555555c28069 in _fsm_inst_state_chg_T (fi=0x6120000048a0, state=0, timeouts_array=0x55555635a3e0 <lchan_fsm_timeouts>, T_defs=0x55555644aee0 <gsm_network_T_defs>, default_timeout=5,
file=0x555555eb3640 "git/osmo-bsc/src/osmo-bsc/lchan_fsm.c", line=1282) at git/osmo-bsc/src/osmo-bsc/gsm_timers.c:189
t = 0x0
val = 32767
#13 0x0000555555ce317e in lchan_fsm_timer_cb (fi=0x6120000048a0) at git/osmo-bsc/src/osmo-bsc/lchan_fsm.c:1282
lchan = 0x7ffff1255cf8
#14 0x00007ffff61f779d in fsm_tmr_cb (data=0x6120000048a0) at git/libosmocore/src/fsm.c:192
rc = 0
fi = 0x6120000048a0
fsm = 0x55555635ac80 <lchan_fsm>
T = 993111
#15 0x00007ffff61dbef7 in osmo_timers_update () at git/libosmocore/src/timer.c:257
current_time = {tv_sec = 1541776319, tv_usec = 190214}
node = 0x7ffff638c7c0 <rate_ctr_timer>
timer_eviction_list = {next = 0x7fffffffde60, prev = 0x7fffffffde60}
this = 0x6120000048e0
work = 0
__mptr = <optimized out>
#16 0x00007ffff61df915 in osmo_select_main (polling=0) at git/libosmocore/src/select.c:254
readset = {__fds_bits = {0 <repeats 16 times>}}
writeset = {__fds_bits = {0 <repeats 16 times>}}
exceptset = {__fds_bits = {0 <repeats 16 times>}}
rc = 0
no_time = {tv_sec = 0, tv_usec = 0}
#17 0x0000555555d5d482 in main (argc=4, argv=0x7fffffffe2e8) at git/osmo-bsc/src/osmo-bsc/osmo_bsc_main.c:929
msc = 0x60f000000198
--Type <RET> for more, q to quit, c to continue without paging--
data = 0x60f000000190
rc = 0
Updated by neels over 5 years ago
- Status changed from New to Feedback
- Assignee set to pespin
- % Done changed from 0 to 80
pespin, can you please reproduce with this patch applied?
https://gerrit.osmocom.org/#/c/osmo-bsc/+/11714
I hope it fixes the situation.
Best also include the logging patch
https://gerrit.osmocom.org/#/c/osmo-bsc/+/11715
(also obtainable in branch neels/os3686)
Thanks!
Updated by pespin over 5 years ago
- Status changed from Feedback to Resolved
- % Done changed from 80 to 100
I could not reproduce the issue, let's hope those patches fix it.
Actions
