Project

General

Profile

Bug #4688

TC_chopped_ipa_ping causes use-after-free abort in ipaccess_drop() / msgb_free(e1i_ts->pending_msg); because of recent libosmo-abis commit "ipaccess: Drop e1inp_line reference in ipacess_drop()"

Added by neels 5 days ago. Updated 4 days ago.

Status:
Feedback
Priority:
Immediate
Assignee:
Category:
-
Target version:
-
Start date:
07/31/2020
Due date:
% Done:

90%

Spec Reference:

Description

ran a ttcn3-bsc-test run and got a double free of e1i_ts->pending_msg

recording the log output here first, cause, reproducability etc are not yet known


Related issues

Related to OsmoBSC - Bug #4624: osmo-bsc leaks memoryFeedback06/20/2020

History

#1 Updated by neels 5 days ago

20200730150307752 DLMI ERROR (bts=0,trx=0) Lost E1 RSL link (osmo_bsc_main.c:389)
20200730150307752 DTS DEBUG timeslot(0-0-0-NONE)[0x612000007ea0]{NOT_INITIALIZED}: Received Event TS_EV_RSL_DOWN (osmo_bsc_main.c:339)
20200730150307752 DTS DEBUG timeslot(0-0-1-NONE)[0x612000007d20]{NOT_INITIALIZED}: Received Event TS_EV_RSL_DOWN (osmo_bsc_main.c:339)
20200730150307752 DTS DEBUG timeslot(0-0-2-NONE)[0x612000007ba0]{NOT_INITIALIZED}: Received Event TS_EV_RSL_DOWN (osmo_bsc_main.c:339)
20200730150307752 DTS DEBUG timeslot(0-0-3-NONE)[0x612000007a20]{NOT_INITIALIZED}: Received Event TS_EV_RSL_DOWN (osmo_bsc_main.c:339)
20200730150307753 DTS DEBUG timeslot(0-0-4-NONE)[0x6120000078a0]{NOT_INITIALIZED}: Received Event TS_EV_RSL_DOWN (osmo_bsc_main.c:339)
20200730150307753 DTS DEBUG timeslot(0-0-5-NONE)[0x612000007720]{NOT_INITIALIZED}: Received Event TS_EV_RSL_DOWN (osmo_bsc_main.c:339)
20200730150307753 DTS DEBUG timeslot(0-0-6-NONE)[0x6120000075a0]{NOT_INITIALIZED}: Received Event TS_EV_RSL_DOWN (osmo_bsc_main.c:339)
20200730150307754 DTS DEBUG timeslot(0-0-7-NONE)[0x612000007420]{NOT_INITIALIZED}: Received Event TS_EV_RSL_DOWN (osmo_bsc_main.c:339)
20200730150307754 DTS DEBUG timeslot(0-0-0-NONE)[0x612000007ea0]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN (bts_trx.c:190)
20200730150307755 DTS DEBUG timeslot(0-0-1-NONE)[0x612000007d20]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN (bts_trx.c:190)
20200730150307755 DTS DEBUG timeslot(0-0-2-NONE)[0x612000007ba0]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN (bts_trx.c:190)
20200730150307755 DTS DEBUG timeslot(0-0-3-NONE)[0x612000007a20]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN (bts_trx.c:190)
20200730150307755 DTS DEBUG timeslot(0-0-4-NONE)[0x6120000078a0]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN (bts_trx.c:190)
20200730150307755 DTS DEBUG timeslot(0-0-5-NONE)[0x612000007720]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN (bts_trx.c:190)
20200730150307755 DTS DEBUG timeslot(0-0-6-NONE)[0x6120000075a0]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN (bts_trx.c:190)
20200730150307755 DTS DEBUG timeslot(0-0-7-NONE)[0x612000007420]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN (bts_trx.c:190)
20200730150307758 DLINP NOTICE 0.0.0.0:3002 accept()ed new link from 172.18.2.100:33625 (ipa.c:287)
20200730150307759 DNM DEBUG (bts=0) Get Attr (trx=255) (abis_nm.c:1777)
20200730150307759 DNM DEBUG (bts=0) Get Attr (trx=0) (abis_nm.c:1777)
20200730150307759 DNM DEBUG OC=SITE-MANAGER(00) INST=(ff,ff,ff): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Locked  (abis_nm.c:276)
20200730150307759 DNM DEBUG OC=SITE-MANAGER(00) INST=(ff,ff,ff): Sending OPSTART (abis_nm.c:2134)
20200730150307760 DNM DEBUG OC=BTS(01) INST=(00,ff,ff): STATE CHG: OP_STATE=NULL AVAIL=Dependency(05) ADM=Locked  (abis_nm.c:276)
20200730150307760 DNM DEBUG (bts=0) Set BTS Attr (abis_nm.c:1795)
20200730150307760 DNM DEBUG OC=BTS(01) INST=(00,ff,ff): Sending OPSTART (abis_nm.c:2134)
20200730150307760 DNM DEBUG OC=GPRS-NSE(f0) INST=(00,ff,ff): STATE CHG: OP_STATE=NULL AVAIL=Dependency(05) ADM=Locked  (abis_nm.c:276)
20200730150307760 DNM DEBUG OC=GPRS-NSE(f0) INST=(00,ff,ff): Sending OPSTART (abis_nm.c:2134)
20200730150307760 DNM DEBUG OC=GPRS-CELL(f1) INST=(00,ff,ff): STATE CHG: OP_STATE=NULL AVAIL=Dependency(05) ADM=Locked  (abis_nm.c:276)
20200730150307760 DNM DEBUG OC=GPRS-CELL(f1) INST=(00,00,ff): Sending OPSTART (abis_nm.c:2134)
20200730150307761 DNM DEBUG OC=GPRS-NSVC(f2) INST=(00,00,ff): STATE CHG: OP_STATE=NULL AVAIL=Dependency(05) ADM=Locked  (abis_nm.c:276)
20200730150307761 DNM DEBUG OC=GPRS-NSVC(f2) INST=(00,00,ff): Sending OPSTART (abis_nm.c:2134)
20200730150307761 DNM DEBUG OC=GPRS-NSVC(f2) INST=(00,01,ff): STATE CHG: OP_STATE=Disabled AVAIL=Off line(03) ADM=Locked  (abis_nm.c:276)
20200730150307761 DNM DEBUG OC=RADIO-CARRIER(02) INST=(00,00,ff): STATE CHG: OP_STATE=NULL AVAIL=Power off(02) ADM=Locked  (abis_nm.c:276)
20200730150307762 DNM DEBUG OC=BASEBAND-TRANSCEIVER(04) INST=(00,00,ff): STATE CHG: OP_STATE=NULL AVAIL=Power off(02) ADM=Locked  (abis_nm.c:276)
20200730150307763 DNM DEBUG OC=CHANNEL(03) INST=(00,00,00): STATE CHG: OP_STATE=NULL AVAIL=Power off(02) ADM=Locked  (abis_nm.c:276)
20200730150307763 DNM DEBUG OC=CHANNEL(03) INST=(00,00,01): STATE CHG: OP_STATE=NULL AVAIL=Power off(02) ADM=Locked  (abis_nm.c:276)
20200730150307764 DNM DEBUG OC=CHANNEL(03) INST=(00,00,02): STATE CHG: OP_STATE=NULL AVAIL=Power off(02) ADM=Locked  (abis_nm.c:276)
20200730150307764 DNM DEBUG OC=CHANNEL(03) INST=(00,00,03): STATE CHG: OP_STATE=NULL AVAIL=Power off(02) ADM=Locked  (abis_nm.c:276)
20200730150307765 DNM DEBUG OC=CHANNEL(03) INST=(00,00,04): STATE CHG: OP_STATE=NULL AVAIL=Power off(02) ADM=Locked  (abis_nm.c:276)
20200730150307765 DNM DEBUG OC=CHANNEL(03) INST=(00,00,05): STATE CHG: OP_STATE=NULL AVAIL=Power off(02) ADM=Locked  (abis_nm.c:276)
20200730150307765 DNM DEBUG OC=CHANNEL(03) INST=(00,00,06): STATE CHG: OP_STATE=NULL AVAIL=Power off(02) ADM=Locked  (abis_nm.c:276)
20200730150307766 DNM DEBUG OC=CHANNEL(03) INST=(00,00,07): STATE CHG: OP_STATE=NULL AVAIL=Power off(02) ADM=Locked  (abis_nm.c:276)
20200730150307766 DNM DEBUG OC=BTS(01) INST=(00,ff,ff): Get Attributes Response for BTS0 (abis_nm.c:681)
20200730150307766 DNM DEBUG BTS0 Get Attributes Response Info: 78 bytes total with 0 unreported attributes (abis_nm.c:543)
20200730150307766 DNM NOTICE BTS0 Get Attributes Response: reported unexpectedly long (3 bytes) feature vector - most likely it was compiled against newer BSC headers. Consider upgrading your BSC to later version. (abis_nm.c:585)
20200730150307766 DNM NOTICE BTS0 feature 'GPRS' reported via OML does not match statically set feature: 0 != 1. Please fix. (abis_nm.c:595)
20200730150307766 DNM NOTICE BTS0 feature 'EGPRS' reported via OML does not match statically set feature: 0 != 1. Please fix. (abis_nm.c:595)
20200730150307766 DNM NOTICE BTS0 feature 'ETWS Primary Notification via PCH' reported via OML does not match statically set feature: 1 != 0. Please fix. (abis_nm.c:595)
20200730150307766 DNM NOTICE BTS0 feature 'BSS Paging Coordination' reported via OML does not match statically set feature: 0 != 1. Please fix. (abis_nm.c:595)
20200730150307766 DNM NOTICE OC=BTS(01) INST=(00,ff,ff): BTS0: ARI reported sw[0/2]: osmobts is 1.2.0.194-3d5c (abis_nm.c:619)
20200730150307766 DNM NOTICE BTS0 reported variant: osmo-bts-omldummy (abis_nm.c:526)
20200730150307767 DNM DEBUG OC=BASEBAND-TRANSCEIVER(04) INST=(00,00,ff): Get Attributes Response for BTS0 (abis_nm.c:681)
20200730150307767 DNM DEBUG BTS0 Get Attributes Response Info: 34 bytes total with 1 unreported attributes (abis_nm.c:543)
20200730150307767 DNM ERROR BTS0 Attribute Manufacturer Dependent State is unreported (abis_nm.c:548)
20200730150307767 DNM NOTICE OC=BASEBAND-TRANSCEIVER(04) INST=(00,00,ff): BTS0: ARI reported sw[0/1]: TRX_PHY_VERSION is Unknown (abis_nm.c:619)
20200730150307767 DNM DEBUG OC=SITE-MANAGER(00) INST=(ff,ff,ff): bts=0 Opstart ACK (abis_nm.c:822)
20200730150307767 DNM DEBUG OC=RADIO-CARRIER(02) INST=(00,00,ff): STATE CHG: OP_STATE=Disabled AVAIL=OK(ff) ADM=Locked  (abis_nm.c:276)
20200730150307768 DRSL DEBUG (bts=0,trx=0) ACC RAMP: administrative state Unlocked -> Locked (acc.c:165)
20200730150307768 DRSL DEBUG (bts=0,trx=0) ACC RAMP: operational state NULL -> Disabled (acc.c:168)
20200730150307768 DRSL DEBUG (bts=0,trx=0) ACC RAMP: ignoring state change because RSL link is down (acc.c:177)
20200730150307768 DNM DEBUG OC=RADIO-CARRIER(02) INST=(00,00,ff): Sending OPSTART (abis_nm.c:2134)
20200730150307768 DRSL DEBUG (bts=0,trx=0) ACC RAMP: administrative state Unlocked -> Locked (acc.c:165)
20200730150307768 DRSL DEBUG (bts=0,trx=0) ACC RAMP: operational state NULL -> Disabled (acc.c:168)
20200730150307768 DRSL DEBUG (bts=0,trx=0) ACC RAMP: ignoring state change because RSL link is down (acc.c:177)
20200730150307768 DRSL DEBUG (bts=0,trx=0) ACC RAMP: administrative state Unlocked -> Locked (acc.c:165)
20200730150307768 DRSL DEBUG (bts=0,trx=0) ACC RAMP: operational state NULL -> Disabled (acc.c:168)
20200730150307768 DRSL DEBUG (bts=0,trx=0) ACC RAMP: ignoring state change because RSL link is down (acc.c:177)
20200730150307768 DRSL DEBUG (bts=0,trx=0) ACC RAMP: administrative state Unlocked -> Locked (acc.c:165)
20200730150307768 DRSL DEBUG (bts=0,trx=0) ACC RAMP: operational state NULL -> Disabled (acc.c:168)
20200730150307768 DRSL DEBUG (bts=0,trx=0) ACC RAMP: ignoring state change because RSL link is down (acc.c:177)
20200730150307768 DNM DEBUG OC=BASEBAND-TRANSCEIVER(04) INST=(00,00,ff): STATE CHG: OP_STATE=NULL AVAIL=OK(ff) ADM=Locked  (abis_nm.c:276)
20200730150307768 DNM DEBUG OC=CHANNEL(03) INST=(00,00,00): STATE CHG: OP_STATE=Disabled AVAIL=Dependency(05) ADM=Locked  (abis_nm.c:276)
20200730150307769 DNM DEBUG OC=CHANNEL(03) INST=(00,00,00): Set Chan Attr (bts=0,trx=0,ts=0) (abis_nm.c:2010)
20200730150307769 DNM DEBUG OC=CHANNEL(03) INST=(00,00,00): abis_nm_set_channel_attr(): sending [L2]> 80 80 00 09 [L3]> 47 03 00 00 00 0d 07 40 02  (abis_nm.c:2067)
20200730150307769 DNM DEBUG OC=CHANNEL(03) INST=(00,00,00): Sending OPSTART (abis_nm.c:2134)
20200730150307769 DNM DEBUG OC=CHANNEL(03) INST=(00,00,01): STATE CHG: OP_STATE=Disabled AVAIL=Dependency(05) ADM=Locked  (abis_nm.c:276)
20200730150307769 DNM DEBUG OC=CHANNEL(03) INST=(00,00,01): Set Chan Attr (bts=0,trx=0,ts=1) (abis_nm.c:2010)
20200730150307769 DNM DEBUG OC=CHANNEL(03) INST=(00,00,01): abis_nm_set_channel_attr(): sending [L2]> 80 80 00 09 [L3]> 47 03 00 00 01 0d 00 40 02  (abis_nm.c:2067)
20200730150307770 DNM DEBUG OC=CHANNEL(03) INST=(00,00,01): Sending OPSTART (abis_nm.c:2134)
20200730150307770 DNM DEBUG OC=CHANNEL(03) INST=(00,00,02): STATE CHG: OP_STATE=Disabled AVAIL=Dependency(05) ADM=Locked  (abis_nm.c:276)
20200730150307771 DNM DEBUG OC=CHANNEL(03) INST=(00,00,02): Set Chan Attr (bts=0,trx=0,ts=2) (abis_nm.c:2010)
20200730150307771 DNM DEBUG OC=CHANNEL(03) INST=(00,00,02): abis_nm_set_channel_attr(): sending [L2]> 80 80 00 09 [L3]> 47 03 00 00 02 0d 00 40 02  (abis_nm.c:2067)
20200730150307771 DNM DEBUG OC=CHANNEL(03) INST=(00,00,02): Sending OPSTART (abis_nm.c:2134)
20200730150307771 DLINP NOTICE 0.0.0.0:3003 accept()ed new link from 172.18.2.203:9999 (ipa.c:287)
20200730150307772 DNM DEBUG OC=CHANNEL(03) INST=(00,00,03): STATE CHG: OP_STATE=Disabled AVAIL=Dependency(05) ADM=Locked  (abis_nm.c:276)
20200730150307772 DNM DEBUG OC=CHANNEL(03) INST=(00,00,03): Set Chan Attr (bts=0,trx=0,ts=3) (abis_nm.c:2010)
20200730150307773 DNM DEBUG OC=CHANNEL(03) INST=(00,00,03): abis_nm_set_channel_attr(): sending [L2]> 80 80 00 09 [L3]> 47 03 00 00 03 0d 00 40 02  (abis_nm.c:2067)
20200730150307773 DNM DEBUG OC=CHANNEL(03) INST=(00,00,03): Sending OPSTART (abis_nm.c:2134)
20200730150307773 DNM DEBUG OC=CHANNEL(03) INST=(00,00,04): STATE CHG: OP_STATE=Disabled AVAIL=Dependency(05) ADM=Locked  (abis_nm.c:276)
20200730150307773 DNM DEBUG OC=CHANNEL(03) INST=(00,00,04): Set Chan Attr (bts=0,trx=0,ts=4) (abis_nm.c:2010)
20200730150307773 DNM DEBUG OC=CHANNEL(03) INST=(00,00,04): abis_nm_set_channel_attr(): sending [L2]> 80 80 00 09 [L3]> 47 03 00 00 04 0d 00 40 02  (abis_nm.c:2067)
20200730150307773 DNM DEBUG OC=CHANNEL(03) INST=(00,00,04): Sending OPSTART (abis_nm.c:2134)
20200730150307773 DNM DEBUG OC=CHANNEL(03) INST=(00,00,05): STATE CHG: OP_STATE=Disabled AVAIL=Dependency(05) ADM=Locked  (abis_nm.c:276)
20200730150307773 DNM DEBUG OC=CHANNEL(03) INST=(00,00,05): Set Chan Attr (bts=0,trx=0,ts=5) (abis_nm.c:2010)
20200730150307773 DNM DEBUG OC=CHANNEL(03) INST=(00,00,05): abis_nm_set_channel_attr(): sending [L2]> 80 80 00 09 [L3]> 47 03 00 00 05 0d 01 40 02  (abis_nm.c:2067)
20200730150307773 DNM DEBUG OC=CHANNEL(03) INST=(00,00,05): Sending OPSTART (abis_nm.c:2134)
20200730150307773 DNM DEBUG OC=CHANNEL(03) INST=(00,00,06): STATE CHG: OP_STATE=Disabled AVAIL=Dependency(05) ADM=Locked  (abis_nm.c:276)
20200730150307774 DNM DEBUG OC=CHANNEL(03) INST=(00,00,06): Set Chan Attr (bts=0,trx=0,ts=6) (abis_nm.c:2010)
20200730150307774 DNM DEBUG OC=CHANNEL(03) INST=(00,00,06): abis_nm_set_channel_attr(): sending [L2]> 80 80 00 09 [L3]> 47 03 00 00 06 0d 0d 40 02  (abis_nm.c:2067)
20200730150307774 DNM DEBUG OC=CHANNEL(03) INST=(00,00,06): Sending OPSTART (abis_nm.c:2134)
20200730150307774 DNM DEBUG OC=CHANNEL(03) INST=(00,00,07): STATE CHG: OP_STATE=Disabled AVAIL=Dependency(05) ADM=Locked  (abis_nm.c:276)
20200730150307774 DNM DEBUG OC=CHANNEL(03) INST=(00,00,07): Set Chan Attr (bts=0,trx=0,ts=7) (abis_nm.c:2010)
20200730150307774 DNM DEBUG OC=CHANNEL(03) INST=(00,00,07): abis_nm_set_channel_attr(): sending [L2]> 80 80 00 09 [L3]> 47 03 00 00 07 0d 0d 40 02  (abis_nm.c:2067)
20200730150307774 DNM DEBUG OC=CHANNEL(03) INST=(00,00,07): Sending OPSTART (abis_nm.c:2134)
20200730150307774 DNM DEBUG OC=RADIO-CARRIER(02) INST=(00,00,ff): Software Activated Report (abis_nm.c:472)
20200730150307774 DNM DEBUG (bts=0,trx=0) Set TRX Attr (abis_nm.c:1812)
20200730150307774 DNM DEBUG OC=RADIO-CARRIER(02) INST=(00,00,ff): Sending OPSTART (abis_nm.c:2134)
20200730150307775 DNM DEBUG OC=BASEBAND-TRANSCEIVER(04) INST=(00,00,ff): Software Activated Report (abis_nm.c:472)
20200730150307775 DNM DEBUG OC=BASEBAND-TRANSCEIVER(04) INST=(00,00,ff): Sending OPSTART (abis_nm.c:2134)
20200730150307775 DNM INFO (bts=0,trx=0) IPA RSL CONNECT IP=0.0.0.0 PORT=3003 STREAM=0x00 (abis_nm.c:2980)
20200730150307775 DNM DEBUG OC=BTS(01) INST=(00,ff,ff): Set BTS Attribute ACK (abis_nm.c:960)
20200730150307775 DNM DEBUG OC=BTS(01) INST=(00,ff,ff): STATE CHG: OP_STATE=NULL AVAIL=Dependency(05) ADM=Unlocked  (abis_nm.c:276)
20200730150307776 DNM DEBUG OC=BTS(01) INST=(00,ff,ff): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Unlocked  (abis_nm.c:276)
20200730150307776 DNM DEBUG OC=BTS(01) INST=(00,ff,ff): bts=0 Opstart ACK (abis_nm.c:822)
20200730150307776 DNM DEBUG OC=GPRS-NSE(f0) INST=(00,ff,ff): Rx IPACCESS(0xf6): 9d 00 02 04 d2 a0 00 07 03 03 03 03 1e 03 0a a1 00 0b 03 03 03 03 03 0a 03 0a 03 0a 03  (abis_nm.c:2797)
20200730150307776 DNM DEBUG OC=GPRS-NSE(f0) INST=(00,ff,ff): SET ATTR ACK (abis_nm.c:2854)
20200730150307776 DNM DEBUG OC=GPRS-NSE(f0) INST=(00,ff,ff): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Locked  (abis_nm.c:276)
20200730150307776 DNM DEBUG OC=GPRS-NSE(f0) INST=(00,ff,ff): bts=0 Opstart ACK (abis_nm.c:822)
20200730150307776 DNM DEBUG OC=GPRS-CELL(f1) INST=(00,00,ff): Rx IPACCESS(0xf6): 9a 00 01 00 9c 00 02 05 03 9e 00 02 04 d2 a3 00 09 14 05 05 a0 05 0a 04 08 0f a8 00 02 0f 00 a9 00 05 00 fa 00 fa 02  (abis_nm.c:2797)
20200730150307776 DNM DEBUG OC=GPRS-CELL(f1) INST=(00,00,ff): SET ATTR ACK (abis_nm.c:2854)
20200730150307777 DNM DEBUG OC=GPRS-CELL(f1) INST=(00,ff,ff): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Locked  (abis_nm.c:276)
20200730150307777 DNM DEBUG OC=GPRS-CELL(f1) INST=(00,ff,ff): bts=0 Opstart ACK (abis_nm.c:822)
20200730150307777 DNM DEBUG OC=GPRS-CELL(f1) INST=(00,ff,ff): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Unlocked  (abis_nm.c:276)
20200730150307777 DNM DEBUG OC=GPRS-NSE(f0) INST=(00,ff,ff): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Unlocked  (abis_nm.c:276)
20200730150307777 DNM DEBUG OC=GPRS-NSVC(f2) INST=(00,00,ff): Rx IPACCESS(0xf6): 9f 00 02 04 d2 a2 00 08 59 d8 c0 a8 64 ef 59 d8  (abis_nm.c:2797)
20200730150307777 DNM DEBUG OC=GPRS-NSVC(f2) INST=(00,00,ff): SET ATTR ACK (abis_nm.c:2854)
20200730150307778 DNM DEBUG OC=GPRS-NSVC(f2) INST=(00,00,ff): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Locked  (abis_nm.c:276)
20200730150307778 DNM DEBUG OC=GPRS-NSVC(f2) INST=(00,00,ff): bts=0 Opstart ACK (abis_nm.c:822)
20200730150307778 DNM DEBUG OC=GPRS-NSVC(f2) INST=(00,00,ff): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Unlocked  (abis_nm.c:276)
20200730150307778 DNM DEBUG OC=RADIO-CARRIER(02) INST=(00,00,ff): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Locked  (abis_nm.c:276)
20200730150307778 DRSL DEBUG (bts=0,trx=0) ACC RAMP: administrative state Unlocked -> Locked (acc.c:165)
20200730150307778 DRSL DEBUG (bts=0,trx=0) ACC RAMP: operational state Disabled -> Enabled (acc.c:168)
20200730150307778 DRSL DEBUG (bts=0,trx=0) ACC RAMP: ignoring state change because RSL link is down (acc.c:177)
20200730150307778 DRSL DEBUG (bts=0,trx=0) ACC RAMP: administrative state Unlocked -> Locked (acc.c:165)
20200730150307778 DRSL DEBUG (bts=0,trx=0) ACC RAMP: operational state Disabled -> Enabled (acc.c:168)
20200730150307778 DRSL DEBUG (bts=0,trx=0) ACC RAMP: ignoring state change because RSL link is down (acc.c:177)
20200730150307778 DRSL DEBUG (bts=0,trx=0) ACC RAMP: administrative state Unlocked -> Locked (acc.c:165)
20200730150307778 DRSL DEBUG (bts=0,trx=0) ACC RAMP: operational state Disabled -> Enabled (acc.c:168)
20200730150307778 DRSL DEBUG (bts=0,trx=0) ACC RAMP: ignoring state change because RSL link is down (acc.c:177)
20200730150307778 DRSL DEBUG (bts=0,trx=0) ACC RAMP: administrative state Unlocked -> Locked (acc.c:165)
20200730150307779 DRSL DEBUG (bts=0,trx=0) ACC RAMP: operational state Disabled -> Enabled (acc.c:168)
20200730150307779 DRSL DEBUG (bts=0,trx=0) ACC RAMP: ignoring state change because RSL link is down (acc.c:177)
20200730150307779 DNM DEBUG OC=RADIO-CARRIER(02) INST=(00,00,ff): bts=0 Opstart ACK (abis_nm.c:822)
20200730150307779 DNM DEBUG OC=CHANNEL(03) INST=(00,00,00): Set Channel Attributes ACK (abis_nm.c:943)
20200730150307779 DNM DEBUG OC=CHANNEL(03) INST=(00,00,00): STATE CHG: OP_STATE=Disabled AVAIL=Dependency(05) ADM=Unlocked  (abis_nm.c:276)
20200730150307779 DNM DEBUG OC=CHANNEL(03) INST=(00,00,00): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Unlocked  (abis_nm.c:276)
20200730150307779 DNM DEBUG OC=CHANNEL(03) INST=(00,00,00): bts=0 Opstart ACK (abis_nm.c:822)
20200730150307779 DTS DEBUG timeslot(0-0-0-NONE)[0x612000007ea0]{NOT_INITIALIZED}: Received Event TS_EV_OML_READY (bts_ipaccess_nanobts.c:316)
20200730150307779 DTS DEBUG timeslot(0-0-0-CCCH_SDCCH4_CBCH)[0x612000007ea0]{NOT_INITIALIZED}: (pchan_is=NONE) max lchans: 4 (timeslot_fsm.c:197)
20200730150307779 DCHAN DEBUG lchan(0-0-0-CCCH_SDCCH4_CBCH)[0x6120000411a0]{UNUSED}: Allocated (fsm.c:461)
20200730150307779 DCHAN DEBUG lchan(0-0-0-CCCH_SDCCH4_CBCH)[0x6120000411a0]{UNUSED}: is child of timeslot(0-0-0-CCCH_SDCCH4_CBCH)[0x612000007ea0] (fsm.c:491)
20200730150307779 DCHAN DEBUG lchan(0-0-0-CCCH_SDCCH4_CBCH-0)[0x6120000411a0]{UNUSED}: new lchan (lchan_fsm.c:367)
20200730150307779 DCHAN DEBUG lchan(0-0-0-CCCH_SDCCH4_CBCH)[0x61200003f520]{UNUSED}: Allocated (fsm.c:461)
20200730150307779 DCHAN DEBUG lchan(0-0-0-CCCH_SDCCH4_CBCH)[0x61200003f520]{UNUSED}: is child of timeslot(0-0-0-CCCH_SDCCH4_CBCH)[0x612000007ea0] (fsm.c:491)
20200730150307780 DCHAN DEBUG lchan(0-0-0-CCCH_SDCCH4_CBCH-1)[0x61200003f520]{UNUSED}: new lchan (lchan_fsm.c:367)
20200730150307780 DCHAN DEBUG lchan(0-0-0-CCCH_SDCCH4_CBCH)[0x61200000c520]{UNUSED}: Allocated (fsm.c:461)
20200730150307780 DCHAN DEBUG lchan(0-0-0-CCCH_SDCCH4_CBCH)[0x61200000c520]{UNUSED}: is child of timeslot(0-0-0-CCCH_SDCCH4_CBCH)[0x612000007ea0] (fsm.c:491)
20200730150307780 DCHAN DEBUG lchan(0-0-0-CCCH_SDCCH4_CBCH-2)[0x61200000c520]{UNUSED}: new lchan (lchan_fsm.c:367)
20200730150307780 DCHAN DEBUG lchan(0-0-0-CCCH_SDCCH4_CBCH)[0x6120000333a0]{UNUSED}: Allocated (fsm.c:461)
20200730150307780 DCHAN DEBUG lchan(0-0-0-CCCH_SDCCH4_CBCH)[0x6120000333a0]{UNUSED}: is child of timeslot(0-0-0-CCCH_SDCCH4_CBCH)[0x612000007ea0] (fsm.c:491)
20200730150307780 DCHAN DEBUG lchan(0-0-0-CCCH_SDCCH4_CBCH-3)[0x6120000333a0]{UNUSED}: new lchan (lchan_fsm.c:367)
20200730150307780 DTS DEBUG timeslot(0-0-0-CCCH_SDCCH4_CBCH)[0x612000007ea0]{NOT_INITIALIZED}: lchans initialized: 4 (timeslot_fsm.c:218)
20200730150307780 DTS DEBUG timeslot(0-0-0-CCCH_SDCCH4_CBCH)[0x612000007ea0]{NOT_INITIALIZED}: No RSL link yet (timeslot_fsm.c:231)
20200730150307780 DNM DEBUG OC=CHANNEL(03) INST=(00,00,01): Set Channel Attributes ACK (abis_nm.c:943)
20200730150307780 DNM DEBUG OC=CHANNEL(03) INST=(00,00,01): STATE CHG: OP_STATE=Disabled AVAIL=Dependency(05) ADM=Unlocked  (abis_nm.c:276)
20200730150307780 DNM DEBUG OC=CHANNEL(03) INST=(00,00,01): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Unlocked  (abis_nm.c:276)
20200730150307780 DNM DEBUG OC=CHANNEL(03) INST=(00,00,01): bts=0 Opstart ACK (abis_nm.c:822)
20200730150307780 DTS DEBUG timeslot(0-0-1-NONE)[0x612000007d20]{NOT_INITIALIZED}: Received Event TS_EV_OML_READY (bts_ipaccess_nanobts.c:316)
20200730150307781 DTS DEBUG timeslot(0-0-1-TCH_F)[0x612000007d20]{NOT_INITIALIZED}: (pchan_is=NONE) max lchans: 1 (timeslot_fsm.c:197)
20200730150307781 DCHAN DEBUG lchan(0-0-1-TCH_F)[0x6120000402a0]{UNUSED}: Allocated (fsm.c:461)
20200730150307781 DCHAN DEBUG lchan(0-0-1-TCH_F)[0x6120000402a0]{UNUSED}: is child of timeslot(0-0-1-TCH_F)[0x612000007d20] (fsm.c:491)
20200730150307781 DCHAN DEBUG lchan(0-0-1-TCH_F-0)[0x6120000402a0]{UNUSED}: new lchan (lchan_fsm.c:367)
20200730150307781 DTS DEBUG timeslot(0-0-1-TCH_F)[0x612000007d20]{NOT_INITIALIZED}: lchans initialized: 1 (timeslot_fsm.c:218)
20200730150307781 DTS DEBUG timeslot(0-0-1-TCH_F)[0x612000007d20]{NOT_INITIALIZED}: No RSL link yet (timeslot_fsm.c:231)
20200730150307781 DNM DEBUG OC=CHANNEL(03) INST=(00,00,02): Set Channel Attributes ACK (abis_nm.c:943)
20200730150307781 DNM DEBUG OC=CHANNEL(03) INST=(00,00,02): STATE CHG: OP_STATE=Disabled AVAIL=Dependency(05) ADM=Unlocked  (abis_nm.c:276)
20200730150307781 DNM DEBUG OC=CHANNEL(03) INST=(00,00,02): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Unlocked  (abis_nm.c:276)
20200730150307781 DNM DEBUG OC=CHANNEL(03) INST=(00,00,02): bts=0 Opstart ACK (abis_nm.c:822)
20200730150307781 DTS DEBUG timeslot(0-0-2-NONE)[0x612000007ba0]{NOT_INITIALIZED}: Received Event TS_EV_OML_READY (bts_ipaccess_nanobts.c:316)
20200730150307781 DTS DEBUG timeslot(0-0-2-TCH_F)[0x612000007ba0]{NOT_INITIALIZED}: (pchan_is=NONE) max lchans: 1 (timeslot_fsm.c:197)
20200730150307781 DCHAN DEBUG lchan(0-0-2-TCH_F)[0x61200003f0a0]{UNUSED}: Allocated (fsm.c:461)
20200730150307781 DCHAN DEBUG lchan(0-0-2-TCH_F)[0x61200003f0a0]{UNUSED}: is child of timeslot(0-0-2-TCH_F)[0x612000007ba0] (fsm.c:491)
20200730150307781 DCHAN DEBUG lchan(0-0-2-TCH_F-0)[0x61200003f0a0]{UNUSED}: new lchan (lchan_fsm.c:367)
20200730150307782 DTS DEBUG timeslot(0-0-2-TCH_F)[0x612000007ba0]{NOT_INITIALIZED}: lchans initialized: 1 (timeslot_fsm.c:218)
20200730150307782 DTS DEBUG timeslot(0-0-2-TCH_F)[0x612000007ba0]{NOT_INITIALIZED}: No RSL link yet (timeslot_fsm.c:231)
20200730150307782 DNM DEBUG OC=CHANNEL(03) INST=(00,00,03): Set Channel Attributes ACK (abis_nm.c:943)
20200730150307782 DNM DEBUG OC=CHANNEL(03) INST=(00,00,03): STATE CHG: OP_STATE=Disabled AVAIL=Dependency(05) ADM=Unlocked  (abis_nm.c:276)
20200730150307782 DNM DEBUG OC=CHANNEL(03) INST=(00,00,03): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Unlocked  (abis_nm.c:276)
20200730150307782 DNM DEBUG OC=CHANNEL(03) INST=(00,00,03): bts=0 Opstart ACK (abis_nm.c:822)
20200730150307782 DTS DEBUG timeslot(0-0-3-NONE)[0x612000007a20]{NOT_INITIALIZED}: Received Event TS_EV_OML_READY (bts_ipaccess_nanobts.c:316)
20200730150307782 DTS DEBUG timeslot(0-0-3-TCH_F)[0x612000007a20]{NOT_INITIALIZED}: (pchan_is=NONE) max lchans: 1 (timeslot_fsm.c:197)
20200730150307782 DCHAN DEBUG lchan(0-0-3-TCH_F)[0x61200003da20]{UNUSED}: Allocated (fsm.c:461)
20200730150307782 DCHAN DEBUG lchan(0-0-3-TCH_F)[0x61200003da20]{UNUSED}: is child of timeslot(0-0-3-TCH_F)[0x612000007a20] (fsm.c:491)
20200730150307782 DCHAN DEBUG lchan(0-0-3-TCH_F-0)[0x61200003da20]{UNUSED}: new lchan (lchan_fsm.c:367)
20200730150307782 DTS DEBUG timeslot(0-0-3-TCH_F)[0x612000007a20]{NOT_INITIALIZED}: lchans initialized: 1 (timeslot_fsm.c:218)
20200730150307782 DTS DEBUG timeslot(0-0-3-TCH_F)[0x612000007a20]{NOT_INITIALIZED}: No RSL link yet (timeslot_fsm.c:231)
20200730150307782 DNM DEBUG OC=CHANNEL(03) INST=(00,00,04): Set Channel Attributes ACK (abis_nm.c:943)
20200730150307783 DNM DEBUG OC=CHANNEL(03) INST=(00,00,04): STATE CHG: OP_STATE=Disabled AVAIL=Dependency(05) ADM=Unlocked  (abis_nm.c:276)
20200730150307783 DNM DEBUG OC=CHANNEL(03) INST=(00,00,04): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Unlocked  (abis_nm.c:276)
20200730150307783 DNM DEBUG OC=CHANNEL(03) INST=(00,00,04): bts=0 Opstart ACK (abis_nm.c:822)
20200730150307783 DTS DEBUG timeslot(0-0-4-NONE)[0x6120000078a0]{NOT_INITIALIZED}: Received Event TS_EV_OML_READY (bts_ipaccess_nanobts.c:316)
20200730150307783 DTS DEBUG timeslot(0-0-4-TCH_F)[0x6120000078a0]{NOT_INITIALIZED}: (pchan_is=NONE) max lchans: 1 (timeslot_fsm.c:197)
20200730150307783 DCHAN DEBUG lchan(0-0-4-TCH_F)[0x61200003ef20]{UNUSED}: Allocated (fsm.c:461)
20200730150307783 DCHAN DEBUG lchan(0-0-4-TCH_F)[0x61200003ef20]{UNUSED}: is child of timeslot(0-0-4-TCH_F)[0x6120000078a0] (fsm.c:491)
20200730150307783 DCHAN DEBUG lchan(0-0-4-TCH_F-0)[0x61200003ef20]{UNUSED}: new lchan (lchan_fsm.c:367)
20200730150307783 DTS DEBUG timeslot(0-0-4-TCH_F)[0x6120000078a0]{NOT_INITIALIZED}: lchans initialized: 1 (timeslot_fsm.c:218)
20200730150307783 DTS DEBUG timeslot(0-0-4-TCH_F)[0x6120000078a0]{NOT_INITIALIZED}: No RSL link yet (timeslot_fsm.c:231)
20200730150307783 DNM DEBUG OC=CHANNEL(03) INST=(00,00,05): Set Channel Attributes ACK (abis_nm.c:943)
20200730150307783 DNM DEBUG OC=CHANNEL(03) INST=(00,00,05): STATE CHG: OP_STATE=Disabled AVAIL=Dependency(05) ADM=Unlocked  (abis_nm.c:276)
20200730150307784 DNM DEBUG OC=CHANNEL(03) INST=(00,00,05): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Unlocked  (abis_nm.c:276)
20200730150307784 DNM DEBUG OC=CHANNEL(03) INST=(00,00,05): bts=0 Opstart ACK (abis_nm.c:822)
20200730150307784 DTS DEBUG timeslot(0-0-5-NONE)[0x612000007720]{NOT_INITIALIZED}: Received Event TS_EV_OML_READY (bts_ipaccess_nanobts.c:316)
20200730150307784 DTS DEBUG timeslot(0-0-5-TCH_H)[0x612000007720]{NOT_INITIALIZED}: (pchan_is=NONE) max lchans: 2 (timeslot_fsm.c:197)
20200730150307784 DCHAN DEBUG lchan(0-0-5-TCH_H)[0x61200003eda0]{UNUSED}: Allocated (fsm.c:461)
20200730150307784 DCHAN DEBUG lchan(0-0-5-TCH_H)[0x61200003eda0]{UNUSED}: is child of timeslot(0-0-5-TCH_H)[0x612000007720] (fsm.c:491)
20200730150307784 DCHAN DEBUG lchan(0-0-5-TCH_H-0)[0x61200003eda0]{UNUSED}: new lchan (lchan_fsm.c:367)
20200730150307784 DCHAN DEBUG lchan(0-0-5-TCH_H)[0x612000034ba0]{UNUSED}: Allocated (fsm.c:461)
20200730150307784 DCHAN DEBUG lchan(0-0-5-TCH_H)[0x612000034ba0]{UNUSED}: is child of timeslot(0-0-5-TCH_H)[0x612000007720] (fsm.c:491)
20200730150307784 DCHAN DEBUG lchan(0-0-5-TCH_H-1)[0x612000034ba0]{UNUSED}: new lchan (lchan_fsm.c:367)
20200730150307784 DTS DEBUG timeslot(0-0-5-TCH_H)[0x612000007720]{NOT_INITIALIZED}: lchans initialized: 2 (timeslot_fsm.c:218)
20200730150307784 DTS DEBUG timeslot(0-0-5-TCH_H)[0x612000007720]{NOT_INITIALIZED}: No RSL link yet (timeslot_fsm.c:231)
20200730150307784 DNM DEBUG OC=CHANNEL(03) INST=(00,00,06): Set Channel Attributes ACK (abis_nm.c:943)
20200730150307784 DNM DEBUG OC=CHANNEL(03) INST=(00,00,06): STATE CHG: OP_STATE=Disabled AVAIL=Dependency(05) ADM=Unlocked  (abis_nm.c:276)
20200730150307784 DNM DEBUG OC=CHANNEL(03) INST=(00,00,06): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Unlocked  (abis_nm.c:276)
20200730150307785 DNM DEBUG OC=CHANNEL(03) INST=(00,00,06): bts=0 Opstart ACK (abis_nm.c:822)
20200730150307785 DTS DEBUG timeslot(0-0-6-NONE)[0x6120000075a0]{NOT_INITIALIZED}: Received Event TS_EV_OML_READY (bts_ipaccess_nanobts.c:316)
20200730150307785 DTS DEBUG timeslot(0-0-6-PDCH)[0x6120000075a0]{NOT_INITIALIZED}: (pchan_is=NONE) max lchans: 0 (timeslot_fsm.c:197)
20200730150307785 DTS DEBUG timeslot(0-0-6-PDCH)[0x6120000075a0]{NOT_INITIALIZED}: lchans initialized: 0 (timeslot_fsm.c:218)
20200730150307785 DTS DEBUG timeslot(0-0-6-PDCH)[0x6120000075a0]{NOT_INITIALIZED}: No RSL link yet (timeslot_fsm.c:231)
20200730150307785 DNM DEBUG OC=CHANNEL(03) INST=(00,00,07): Set Channel Attributes ACK (abis_nm.c:943)
20200730150307785 DNM DEBUG OC=CHANNEL(03) INST=(00,00,07): STATE CHG: OP_STATE=Disabled AVAIL=Dependency(05) ADM=Unlocked  (abis_nm.c:276)
20200730150307785 DNM DEBUG OC=CHANNEL(03) INST=(00,00,07): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Unlocked  (abis_nm.c:276)
20200730150307785 DNM DEBUG OC=CHANNEL(03) INST=(00,00,07): bts=0 Opstart ACK (abis_nm.c:822)
20200730150307785 DTS DEBUG timeslot(0-0-7-NONE)[0x612000007420]{NOT_INITIALIZED}: Received Event TS_EV_OML_READY (bts_ipaccess_nanobts.c:316)
20200730150307785 DTS DEBUG timeslot(0-0-7-PDCH)[0x612000007420]{NOT_INITIALIZED}: (pchan_is=NONE) max lchans: 0 (timeslot_fsm.c:197)
20200730150307785 DTS DEBUG timeslot(0-0-7-PDCH)[0x612000007420]{NOT_INITIALIZED}: lchans initialized: 0 (timeslot_fsm.c:218)
20200730150307785 DTS DEBUG timeslot(0-0-7-PDCH)[0x612000007420]{NOT_INITIALIZED}: No RSL link yet (timeslot_fsm.c:231)
20200730150307786 DNM DEBUG OC=RADIO-CARRIER(02) INST=(00,00,ff): Set Radio Carrier Attributes ACK (abis_nm.c:946)
20200730150307786 DRSL DEBUG (bts=0,trx=0) ACC RAMP: administrative state Unlocked -> Unlocked (acc.c:165)
20200730150307786 DRSL DEBUG (bts=0,trx=0) ACC RAMP: operational state Enabled -> Enabled (acc.c:168)
20200730150307786 DRSL DEBUG (bts=0,trx=0) ACC RAMP: ignoring state change because RSL link is down (acc.c:177)
20200730150307786 DRSL DEBUG (bts=0,trx=0) ACC RAMP: administrative state Unlocked -> Unlocked (acc.c:165)
20200730150307786 DRSL DEBUG (bts=0,trx=0) ACC RAMP: operational state Enabled -> Enabled (acc.c:168)
20200730150307786 DRSL DEBUG (bts=0,trx=0) ACC RAMP: ignoring state change because RSL link is down (acc.c:177)
20200730150307786 DRSL DEBUG (bts=0,trx=0) ACC RAMP: administrative state Unlocked -> Unlocked (acc.c:165)
20200730150307786 DRSL DEBUG (bts=0,trx=0) ACC RAMP: operational state Enabled -> Enabled (acc.c:168)
20200730150307786 DRSL DEBUG (bts=0,trx=0) ACC RAMP: ignoring state change because RSL link is down (acc.c:177)
20200730150307786 DRSL DEBUG (bts=0,trx=0) ACC RAMP: administrative state Unlocked -> Unlocked (acc.c:165)
20200730150307786 DRSL DEBUG (bts=0,trx=0) ACC RAMP: operational state Enabled -> Enabled (acc.c:168)
20200730150307786 DRSL DEBUG (bts=0,trx=0) ACC RAMP: ignoring state change because RSL link is down (acc.c:177)
20200730150307786 DNM DEBUG OC=RADIO-CARRIER(02) INST=(00,00,ff): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Unlocked  (abis_nm.c:276)
20200730150307786 DNM DEBUG OC=RADIO-CARRIER(02) INST=(00,00,ff): bts=0 Opstart ACK (abis_nm.c:822)
20200730150307786 DNM DEBUG OC=BASEBAND-TRANSCEIVER(04) INST=(00,00,ff): STATE CHG: OP_STATE=NULL AVAIL=OK(ff) ADM=Unlocked  (abis_nm.c:276)
20200730150307787 DNM DEBUG OC=BASEBAND-TRANSCEIVER(04) INST=(00,00,ff): STATE CHG: OP_STATE=Enabled AVAIL=OK(ff) ADM=Unlocked  (abis_nm.c:276)
20200730150307787 DNM DEBUG OC=BASEBAND-TRANSCEIVER(04) INST=(00,00,ff): bts=0 Opstart ACK (abis_nm.c:822)
20200730150307787 DNM DEBUG OC=BASEBAND-TRANSCEIVER(04) INST=(00,00,ff): Rx IPACCESS(0xe1): 85 00 81 0b bb  (abis_nm.c:2797)
20200730150307787 DNM DEBUG OC=BASEBAND-TRANSCEIVER(04) INST=(00,00,ff): RSL CONNECT ACK PORT=3003 STREAM=0x00  (abis_nm.c:2813)
20200730150308657 DRLL DEBUG (bts=0) channel load average is 0.00% (chan_alloc.c:240)
20200730150308657 DRLL DEBUG (bts=0) T3122 wait indicator set to 10 seconds (chan_alloc.c:253)
20200730150309682 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: Timeout of T4 (fsm.c:322)
20200730150309682 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150309682 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.2,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150309683 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150309683 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150309683 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: Timeout of T4 (fsm.c:322)
20200730150309683 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150309683 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.3,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150309684 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150309684 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150311683 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: Timeout of T4 (fsm.c:322)
20200730150311683 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150311683 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.2,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150311684 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150311684 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150311684 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: Timeout of T4 (fsm.c:322)
20200730150311684 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150311684 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.3,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150311685 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150311685 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150313684 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: Timeout of T4 (fsm.c:322)
20200730150313684 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150313684 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.2,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150313685 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150313685 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150313685 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: Timeout of T4 (fsm.c:322)
20200730150313685 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150313685 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.3,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150313685 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150313686 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150314663 DRLL DEBUG (bts=1) channel load average is 0.00% (chan_alloc.c:240)
20200730150314663 DRLL DEBUG (bts=1) T3122 wait indicator set to 10 seconds (chan_alloc.c:253)
20200730150314663 DRLL DEBUG (bts=2) channel load average is 0.00% (chan_alloc.c:240)
20200730150314663 DRLL DEBUG (bts=2) T3122 wait indicator set to 10 seconds (chan_alloc.c:253)
20200730150315191 DHODEC DEBUG (BTS 0) No congestion check: no minimum for free TCH/F nor TCH/H set (handover_decision_2.c:1847)
20200730150315191 DHODEC DEBUG (BTS 1) No congestion check: no minimum for free TCH/F nor TCH/H set (handover_decision_2.c:1847)
20200730150315191 DHODEC DEBUG (BTS 2) No congestion check: no minimum for free TCH/F nor TCH/H set (handover_decision_2.c:1847)
20200730150315191 DHODEC DEBUG (BTS 3) No congestion check: TRX 0 not usable (handover_decision_2.c:1831)
20200730150315191 DHODEC DEBUG HO algorithm 2: next periodical congestion check in 10 seconds (handover_decision_2.c:163)
20200730150315685 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: Timeout of T4 (fsm.c:322)
20200730150315685 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150315685 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.2,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150315686 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150315686 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150315686 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: Timeout of T4 (fsm.c:322)
20200730150315686 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150315686 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.3,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150315686 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150315687 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150316665 DRLL DEBUG (bts=0) channel load average is 0.00% (chan_alloc.c:240)
20200730150316665 DRLL DEBUG (bts=0) T3122 wait indicator set to 10 seconds (chan_alloc.c:253)
20200730150317686 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: Timeout of T4 (fsm.c:322)
20200730150317686 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150317686 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.2,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150317686 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150317687 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150317687 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: Timeout of T4 (fsm.c:322)
20200730150317687 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150317687 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.3,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150317687 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150317687 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150319687 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: Timeout of T4 (fsm.c:322)
20200730150319687 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150319687 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.2,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150319687 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150319687 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150319687 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: Timeout of T4 (fsm.c:322)
20200730150319688 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150319688 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.3,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150319688 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150319688 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150321688 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: Timeout of T4 (fsm.c:322)
20200730150321688 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150321688 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.2,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150321688 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150321688 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150321688 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: Timeout of T4 (fsm.c:322)
20200730150321688 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150321688 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.3,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150321689 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150321689 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150322671 DRLL DEBUG (bts=1) channel load average is 0.00% (chan_alloc.c:240)
20200730150322671 DRLL DEBUG (bts=1) T3122 wait indicator set to 10 seconds (chan_alloc.c:253)
20200730150322671 DRLL DEBUG (bts=2) channel load average is 0.00% (chan_alloc.c:240)
20200730150322671 DRLL DEBUG (bts=2) T3122 wait indicator set to 10 seconds (chan_alloc.c:253)
20200730150323688 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: Timeout of T4 (fsm.c:322)
20200730150323689 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150323689 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.2,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150323689 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150323689 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150323689 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: Timeout of T4 (fsm.c:322)
20200730150323689 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150323689 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.3,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150323690 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150323690 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150324673 DRLL DEBUG (bts=0) channel load average is 0.00% (chan_alloc.c:240)
20200730150324673 DRLL DEBUG (bts=0) T3122 wait indicator set to 10 seconds (chan_alloc.c:253)
20200730150325192 DHODEC DEBUG (BTS 0) No congestion check: no minimum for free TCH/F nor TCH/H set (handover_decision_2.c:1847)
20200730150325192 DHODEC DEBUG (BTS 1) No congestion check: no minimum for free TCH/F nor TCH/H set (handover_decision_2.c:1847)
20200730150325192 DHODEC DEBUG (BTS 2) No congestion check: no minimum for free TCH/F nor TCH/H set (handover_decision_2.c:1847)
20200730150325192 DHODEC DEBUG (BTS 3) No congestion check: TRX 0 not usable (handover_decision_2.c:1831)
20200730150325192 DHODEC DEBUG HO algorithm 2: next periodical congestion check in 10 seconds (handover_decision_2.c:163)
20200730150325689 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: Timeout of T4 (fsm.c:322)
20200730150325689 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150325690 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.2,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150325690 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150325690 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150325690 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: Timeout of T4 (fsm.c:322)
20200730150325690 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150325690 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.3,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150325691 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150325691 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150327690 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: Timeout of T4 (fsm.c:322)
20200730150327690 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150327690 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.2,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150327691 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150327691 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150327691 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: Timeout of T4 (fsm.c:322)
20200730150327691 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150327691 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.3,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150327692 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150327692 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150329691 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: Timeout of T4 (fsm.c:322)
20200730150329691 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150329691 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.2,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150329692 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150329692 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150329692 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: Timeout of T4 (fsm.c:322)
20200730150329692 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150329692 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.3,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150329693 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150329693 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150330679 DRLL DEBUG (bts=1) channel load average is 0.00% (chan_alloc.c:240)
20200730150330679 DRLL DEBUG (bts=1) T3122 wait indicator set to 10 seconds (chan_alloc.c:253)
20200730150330679 DRLL DEBUG (bts=2) channel load average is 0.00% (chan_alloc.c:240)
20200730150330679 DRLL DEBUG (bts=2) T3122 wait indicator set to 10 seconds (chan_alloc.c:253)
20200730150331692 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: Timeout of T4 (fsm.c:322)
20200730150331692 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150331692 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.2,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150331693 DMSC DEBUG A-RESET(msc-1)[0x612000003ca0]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150331693 DMSC NOTICE A-RESET(msc-1)[0x612000003ca0]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150331693 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: Timeout of T4 (fsm.c:322)
20200730150331693 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: (re)sending BSSMAP RESET message... (a_reset.c:129)
20200730150331693 DMSC NOTICE Sending RESET to MSC: RI=SSN_PC,PC=0.0.3,SSN=BSSAP (osmo_bsc_sigtran.c:102)
20200730150331694 DMSC DEBUG A-RESET(msc-2)[0x612000003b20]{DISC}: state_chg to DISC (a_reset.c:133)
20200730150331694 DMSC NOTICE A-RESET(msc-2)[0x612000003b20]{DISC}: BSSMAP MSC assocation is down, reconnecting... (a_reset.c:85)
20200730150331799 DLINP NOTICE Sign link vanished, dead socket (ipaccess.c:371)
20200730150331799 DLINP ERROR Forcing socket shutdown with no signal link set (ipaccess.c:91)
=================================================================
==53116==ERROR: AddressSanitizer: heap-use-after-free on address 0x62f000119068 at pc 0x7f8ed77d2fcd bp 0x7fff17af89d0 sp 0x7fff17af89c8
READ of size 8 at 0x62f000119068 thread T0
    #0 0x7f8ed77d2fcc in ipaccess_drop ../../../src/libosmo-abis/src/input/ipaccess.c:105
    #1 0x7f8ed77d610e in handle_ts1_read ../../../src/libosmo-abis/src/input/ipaccess.c:417
    #2 0x7f8ed77d610e in ipaccess_fd_cb ../../../src/libosmo-abis/src/input/ipaccess.c:542
    #3 0x7f8ed7dde206 in osmo_fd_disp_fds ../../../src/libosmocore/src/select.c:227
    #4 0x7f8ed7dde206 in _osmo_select_main ../../../src/libosmocore/src/select.c:265
    #5 0x7f8ed7de157a in osmo_select_main_ctx ../../../src/libosmocore/src/select.c:291
    #6 0x55603c04f656 in main ../../../../src/osmo-bsc/src/osmo-bsc/osmo_bsc_main.c:952
    #7 0x7f8ed5d692e0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202e0)
    #8 0x55603c050219 in _start (/usr/local/bin/osmo-bsc+0x3e5219)

0x62f000119068 is located 3176 bytes inside of 48368-byte region [0x62f000118400,0x62f0001240f0)
freed by thread T0 here:
    #0 0x7f8ed9121a10 in free (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1a10)
    #1 0x7f8ed8b3786a in _talloc_free (/usr/lib/x86_64-linux-gnu/libtalloc.so.2+0x486a)

previously allocated by thread T0 here:
    #0 0x7f8ed9121d28 in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1d28)
    #1 0x7f8ed8b39acd in _talloc_zero (/usr/lib/x86_64-linux-gnu/libtalloc.so.2+0x6acd)

SUMMARY: AddressSanitizer: heap-use-after-free ../../../src/libosmo-abis/src/input/ipaccess.c:105 in ipaccess_drop
Shadow bytes around the buggy address:
  0x0c5e8001b1b0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c5e8001b1c0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c5e8001b1d0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c5e8001b1e0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c5e8001b1f0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
=>0x0c5e8001b200: fd fd fd fd fd fd fd fd fd fd fd fd fd[fd]fd fd
  0x0c5e8001b210: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c5e8001b220: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c5e8001b230: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c5e8001b240: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c5e8001b250: 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
  Heap right redzone:      fb
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack partial redzone:   f4
  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
==53116==ABORTING
root@86c1fbdf5ba3:/data#

#2 Updated by neels 5 days ago

pass BSC_Tests.TC_dyn_pdch_ipa_act_deact
pass BSC_Tests.TC_dyn_pdch_ipa_act_nack
pass BSC_Tests.TC_dyn_pdch_osmo_act_deact
pass BSC_Tests.TC_dyn_pdch_osmo_act_nack
pass->FAIL BSC_Tests.TC_chopped_ipa_ping
pass->FAIL BSC_Tests.TC_chopped_ipa_payload
pass->FAIL BSC_Tests.TC_assignment_verify_ms_power_params_ie
pass->FAIL BSC_Tests.TC_early_conn_fail

assuming the cause in/around TC_chopped_ipa_ping

#5 Updated by neels 5 days ago

i can reproduce the issue by running TC_chopped_ipa_ping on current master of all of libosmo* and osmo-bsc.
A first probe of osmo-bsc to find a good bisect didn't show anything,
so the cause might not be an osmo-bsc patch at all. Neither do any libosmo-* patches seem likely causes...

#6 Updated by neels 5 days ago

pespin

I identified the cause:

Recently merged patch [1] introduces a e1inp_line_put2(line, "ipa_bfd"); in ipaccess_drop(),
and the line is still used later in that function.
In the error case, the put() causes deallocation of line and also e1i_ts, which make later uses a use-after-free

[1]

commit b8ea0ff521a3e01c22a9dd1948b9a853521f575e
Refs: 0.8.0-43-gb8ea0ff
Author:     Pau Espin Pedrol <pespin@sysmocom.de>
AuthorDate: Tue Jul 14 13:28:27 2020 +0200
Commit:     Pau Espin Pedrol <pespin@sysmocom.de>
CommitDate: Wed Jul 15 15:39:33 2020 +0200

    ipaccess: Drop e1inp_line reference in ipacess_drop()

    the bfd->data handles a reference to the e1np_line (obtained through
    e1inp_line_get() during bfd setup), so remember to drop it under this
    condition.

    Related: OS#4624
    Change-Id: I418064df04872befe2e936e21768b6ea01263120

This is the function ipaccess_drop():

static int ipaccess_drop(struct osmo_fd *bfd, struct e1inp_line *line)
{
        int ret = 1;
        struct e1inp_ts *e1i_ts = ipaccess_line_ts(bfd, line);

        ipaccess_keepalive_fsm_cleanup(e1i_ts);

        /* Error case: we did not see any ID_RESP yet for this socket. */
        if (bfd->fd != -1) {
                LOGP(DLINP, LOGL_ERROR, "Forcing socket shutdown with " 
                                        "no signal link set\n");
                osmo_fd_unregister(bfd);
                close(bfd->fd);
                bfd->fd = -1;
                /* This is BSC code, ipaccess_drop() is only called for
                   accepted() sockets, hence the bfd holds a reference to
                   e1inp_line in ->data that needs to be released */
                OSMO_ASSERT(bfd->data == line);
                bfd->data = NULL;
                e1inp_line_put2(line, "ipa_bfd");          <---- may deallocate line and e1i_ts
                ret = -ENOENT;
        }

        msgb_free(e1i_ts->pending_msg);                    <---- e1i_ts use after free
        e1i_ts->pending_msg = NULL;

        /* e1inp_sign_link_destroy releases the socket descriptors for us. */
        line->ops->sign_link_down(line);

        return ret;
}

I don't understand yet the get() for "ctor" in e1inp_line_create():
I do see this "ctor" use added in the osmo-bsc logs, but I don't see it removed anywhere.
But there is no "ctor" use tagged on 'line' during that e1inp_line_put2(line, "ipa_bfd").
Nor do i see any code that removes the "ctor" use. What??

#7 Updated by neels 5 days ago

  • Subject changed from hit use-after-free in ipaccess_drop() / msgb_free(e1i_ts->pending_msg); to TC_chopped_ipa_ping causes use-after-free abort in ipaccess_drop() / msgb_free(e1i_ts->pending_msg); because of recent libosmo-abis commit "ipaccess: Drop e1inp_line reference in ipacess_drop()"
  • Assignee set to pespin
  • Priority changed from Normal to Immediate
  • % Done changed from 0 to 20

assigning to pespin, I don't want to revert the entire patch series, instead hoping that you can resolve the issue quickly (or revert yourself)

#8 Updated by neels 5 days ago

  • Related to Bug #4624: osmo-bsc leaks memory added

#9 Updated by neels 5 days ago

Depending on what actions need to be taken, the solution can be:

static int ipaccess_drop(struct osmo_fd *bfd, struct e1inp_line *line)
{
        int ret = 1;
        struct e1inp_ts *e1i_ts = ipaccess_line_ts(bfd, line);

+       e1inp_line_get2(line, __func__);

        ipaccess_keepalive_fsm_cleanup(e1i_ts);

        /* Error case: we did not see any ID_RESP yet for this socket. */
        if (bfd->fd != -1) {
                LOGP(DLINP, LOGL_ERROR, "Forcing socket shutdown with " 
                                        "no signal link set\n");
                osmo_fd_unregister(bfd);
                close(bfd->fd);
                bfd->fd = -1;
                /* This is BSC code, ipaccess_drop() is only called for
                   accepted() sockets, hence the bfd holds a reference to
                   e1inp_line in ->data that needs to be released */
                OSMO_ASSERT(bfd->data == line);
                bfd->data = NULL;
                e1inp_line_put2(line, "ipa_bfd");          <---- may deallocate line and e1i_ts
                ret = -ENOENT;
        }

        msgb_free(e1i_ts->pending_msg);                    <---- e1i_ts use after free
        e1i_ts->pending_msg = NULL;

        /* e1inp_sign_link_destroy releases the socket descriptors for us. */
        line->ops->sign_link_down(line);

+       e1inp_line_put2(line, __func__);
        return ret;
}

or a direct 'return -ENOENT;'

not sure which it should be though.

#10 Updated by neels 5 days ago

(btw, it could be good to remove the " osmo_use_count_free(use_count_entry); " from e1inp_line_use_cb(),
because then if a use token shows up and disappears rapidly, we don't de- and re-allocate use count entries every time.
Zero-count entries are fine to stick around until the used object's deallocation.)

#11 Updated by pespin 4 days ago

  • Status changed from New to In Progress

#12 Updated by pespin 4 days ago

  • Status changed from In Progress to Feedback
  • % Done changed from 20 to 90

Thanks for initial analysis, your proposed patch seems the best way to go here.
https://gerrit.osmocom.org/c/libosmo-abis/+/19478 ipaccess: Fix use-after-free in ipaccess_drop()

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)