Bug #3495
closedosmo-bsc: heap-use-after-free in ipaccess handle_ts1_write() with multitrx (setup failing previously)
100%
Description
Caught by osmo-gsm-tester when testing new setup of 2 nanoBTS attached forming a multiTRX setup (-s voice:nanobts+band-900+mod-bts0-numtrx2+mod-bts0-chanallocdescend -T -l dbg).
[0;m[1;36m20180822124927912 [1;34mDNM[0;m[1;36m <0004> abis_nm.c:702 OC=CHANNEL(03) INST=(00,00,07): bts=0 trx=0 Opstart ACK [0;m[1;31m20180822124927913 [1;34mDTS[0;m[1;31m <0011> bts_ipaccess_nanobts.c:308 timeslot(0-0-7-NONE)[0x61200000a5a0]{NOT_INITIALIZED}: Received Event TS_EV_OML_READY [0;m[1;31m20180822124927913 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:196 timeslot(0-0-7-PDCH)[0x61200000a5a0]{NOT_INITIALIZED}: (pchan_is=NONE) max lchans: 0 [0;m[1;31m20180822124927913 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:217 timeslot(0-0-7-PDCH)[0x61200000a5a0]{NOT_INITIALIZED}: lchans initialized: 0 [0;m[1;31m20180822124927913 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:230 timeslot(0-0-7-PDCH)[0x61200000a5a0]{NOT_INITIALIZED}: No RSL link yet [0;m[1;36m20180822124927913 [1;33mDNM[0;m[1;36m <0004> abis_nm.c:787 OC=RADIO-CARRIER(02) INST=(00,00,ff): CHANGE ADMINISTRATIVE STATE NACK [0;m[1;36mCAUSE=Message cannot be performed [0;m[1;36m20180822124927913 [1;31mDNM[0;m[1;36m <0004> osmo_bsc_main.c:186 Got CHANGE ADMINISTRATIVE STATE NACK going to drop the OML links. [0;m20180822124927913 [1;33mDLINP[0;m <0015> bts_ipaccess_nanobts.c:406 (bts=0) Dropping OML link. [0;m[1;31m20180822124927913 [1;34mDTS[0;m[1;31m <0011> osmo_bsc_main.c:318 timeslot(0-0-0-CCCH_SDCCH4)[0x61200000b020]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;32m20180822124927913 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000033a0]{UNUSED}: Terminating (cause = OSMO_FSM_TERM_REQUEST) [0;m[1;32m20180822124927913 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000033a0]{UNUSED}: Removing from parent timeslot(0-0-0-CCCH_SDCCH4)[0x61200000b020] [0;m[1;32m20180822124927913 [1;34mDCHAN[0;m[1;32m <0010> lchan_fsm.c:354 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000033a0]{UNUSED}: (type=NONE) Clearing lchan state [0;m[1;32m20180822124927913 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000033a0]{UNUSED}: Freeing instance [0;m[1;32m20180822124927914 [1;34mDCHAN[0;m[1;32m <0010> fsm.c:381 lchan(0-0-0-CCCH_SDCCH4-0)[0x6120000033a0]{UNUSED}: Deallocated [0;m[1;31m20180822124927914 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:139 timeslot(0-0-0-CCCH_SDCCH4)[0x61200000b020]{NOT_INITIALIZED}: Received Event TS_EV_LCHAN_UNUSED [0;m[1;32m20180822124927914 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-0-CCCH_SDCCH4-1)[0x612000003220]{UNUSED}: Terminating (cause = OSMO_FSM_TERM_REQUEST) [0;m[1;32m20180822124927914 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-0-CCCH_SDCCH4-1)[0x612000003220]{UNUSED}: Removing from parent timeslot(0-0-0-CCCH_SDCCH4)[0x61200000b020] [0;m[1;32m20180822124927914 [1;34mDCHAN[0;m[1;32m <0010> lchan_fsm.c:354 lchan(0-0-0-CCCH_SDCCH4-1)[0x612000003220]{UNUSED}: (type=NONE) Clearing lchan state [0;m[1;32m20180822124927914 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-0-CCCH_SDCCH4-1)[0x612000003220]{UNUSED}: Freeing instance [0;m[1;32m20180822124927914 [1;34mDCHAN[0;m[1;32m <0010> fsm.c:381 lchan(0-0-0-CCCH_SDCCH4-1)[0x612000003220]{UNUSED}: Deallocated [0;m[1;31m20180822124927914 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:139 timeslot(0-0-0-CCCH_SDCCH4)[0x61200000b020]{NOT_INITIALIZED}: Received Event TS_EV_LCHAN_UNUSED [0;m[1;32m20180822124927914 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-0-CCCH_SDCCH4-2)[0x6120000030a0]{UNUSED}: Terminating (cause = OSMO_FSM_TERM_REQUEST) [0;m[1;32m20180822124927914 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-0-CCCH_SDCCH4-2)[0x6120000030a0]{UNUSED}: Removing from parent timeslot(0-0-0-CCCH_SDCCH4)[0x61200000b020] [0;m[1;32m20180822124927914 [1;34mDCHAN[0;m[1;32m <0010> lchan_fsm.c:354 lchan(0-0-0-CCCH_SDCCH4-2)[0x6120000030a0]{UNUSED}: (type=NONE) Clearing lchan state [0;m[1;32m20180822124927914 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-0-CCCH_SDCCH4-2)[0x6120000030a0]{UNUSED}: Freeing instance [0;m[1;32m20180822124927914 [1;34mDCHAN[0;m[1;32m <0010> fsm.c:381 lchan(0-0-0-CCCH_SDCCH4-2)[0x6120000030a0]{UNUSED}: Deallocated [0;m[1;31m20180822124927914 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:139 timeslot(0-0-0-CCCH_SDCCH4)[0x61200000b020]{NOT_INITIALIZED}: Received Event TS_EV_LCHAN_UNUSED [0;m[1;32m20180822124927914 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-0-CCCH_SDCCH4-3)[0x612000002f20]{UNUSED}: Terminating (cause = OSMO_FSM_TERM_REQUEST) [0;m[1;32m20180822124927914 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-0-CCCH_SDCCH4-3)[0x612000002f20]{UNUSED}: Removing from parent timeslot(0-0-0-CCCH_SDCCH4)[0x61200000b020] [0;m[1;32m20180822124927914 [1;34mDCHAN[0;m[1;32m <0010> lchan_fsm.c:354 lchan(0-0-0-CCCH_SDCCH4-3)[0x612000002f20]{UNUSED}: (type=NONE) Clearing lchan state [0;m[1;32m20180822124927914 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-0-CCCH_SDCCH4-3)[0x612000002f20]{UNUSED}: Freeing instance [0;m[1;32m20180822124927914 [1;34mDCHAN[0;m[1;32m <0010> fsm.c:381 lchan(0-0-0-CCCH_SDCCH4-3)[0x612000002f20]{UNUSED}: Deallocated [0;m[1;31m20180822124927914 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:139 timeslot(0-0-0-CCCH_SDCCH4)[0x61200000b020]{NOT_INITIALIZED}: Received Event TS_EV_LCHAN_UNUSED [0;m[1;31m20180822124927915 [1;34mDTS[0;m[1;31m <0011> osmo_bsc_main.c:318 timeslot(0-0-1-SDCCH8)[0x61200000aea0]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;32m20180822124927915 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-0)[0x612000002da0]{UNUSED}: Terminating (cause = OSMO_FSM_TERM_REQUEST) [0;m[1;32m20180822124927915 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-0)[0x612000002da0]{UNUSED}: Removing from parent timeslot(0-0-1-SDCCH8)[0x61200000aea0] [0;m[1;32m20180822124927915 [1;34mDCHAN[0;m[1;32m <0010> lchan_fsm.c:354 lchan(0-0-1-SDCCH8-0)[0x612000002da0]{UNUSED}: (type=NONE) Clearing lchan state [0;m[1;32m20180822124927915 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-0)[0x612000002da0]{UNUSED}: Freeing instance [0;m[1;32m20180822124927915 [1;34mDCHAN[0;m[1;32m <0010> fsm.c:381 lchan(0-0-1-SDCCH8-0)[0x612000002da0]{UNUSED}: Deallocated [0;m[1;31m20180822124927915 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:139 timeslot(0-0-1-SDCCH8)[0x61200000aea0]{NOT_INITIALIZED}: Received Event TS_EV_LCHAN_UNUSED [0;m[1;32m20180822124927915 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-1)[0x612000002c20]{UNUSED}: Terminating (cause = OSMO_FSM_TERM_REQUEST) [0;m[1;32m20180822124927915 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-1)[0x612000002c20]{UNUSED}: Removing from parent timeslot(0-0-1-SDCCH8)[0x61200000aea0] [0;m[1;32m20180822124927915 [1;34mDCHAN[0;m[1;32m <0010> lchan_fsm.c:354 lchan(0-0-1-SDCCH8-1)[0x612000002c20]{UNUSED}: (type=NONE) Clearing lchan state [0;m[1;32m20180822124927915 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-1)[0x612000002c20]{UNUSED}: Freeing instance [0;m[1;32m20180822124927915 [1;34mDCHAN[0;m[1;32m <0010> fsm.c:381 lchan(0-0-1-SDCCH8-1)[0x612000002c20]{UNUSED}: Deallocated [0;m[1;31m20180822124927915 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:139 timeslot(0-0-1-SDCCH8)[0x61200000aea0]{NOT_INITIALIZED}: Received Event TS_EV_LCHAN_UNUSED [0;m[1;32m20180822124927915 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-2)[0x612000002aa0]{UNUSED}: Terminating (cause = OSMO_FSM_TERM_REQUEST) [0;m[1;32m20180822124927915 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-2)[0x612000002aa0]{UNUSED}: Removing from parent timeslot(0-0-1-SDCCH8)[0x61200000aea0] [0;m[1;32m20180822124927915 [1;34mDCHAN[0;m[1;32m <0010> lchan_fsm.c:354 lchan(0-0-1-SDCCH8-2)[0x612000002aa0]{UNUSED}: (type=NONE) Clearing lchan state [0;m[1;32m20180822124927915 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-2)[0x612000002aa0]{UNUSED}: Freeing instance [0;m[1;32m20180822124927916 [1;34mDCHAN[0;m[1;32m <0010> fsm.c:381 lchan(0-0-1-SDCCH8-2)[0x612000002aa0]{UNUSED}: Deallocated [0;m[1;31m20180822124927916 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:139 timeslot(0-0-1-SDCCH8)[0x61200000aea0]{NOT_INITIALIZED}: Received Event TS_EV_LCHAN_UNUSED [0;m[1;32m20180822124927916 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-3)[0x612000002920]{UNUSED}: Terminating (cause = OSMO_FSM_TERM_REQUEST) [0;m[1;32m20180822124927916 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-3)[0x612000002920]{UNUSED}: Removing from parent timeslot(0-0-1-SDCCH8)[0x61200000aea0] [0;m[1;32m20180822124927916 [1;34mDCHAN[0;m[1;32m <0010> lchan_fsm.c:354 lchan(0-0-1-SDCCH8-3)[0x612000002920]{UNUSED}: (type=NONE) Clearing lchan state [0;m[1;32m20180822124927916 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-3)[0x612000002920]{UNUSED}: Freeing instance [0;m[1;32m20180822124927916 [1;34mDCHAN[0;m[1;32m <0010> fsm.c:381 lchan(0-0-1-SDCCH8-3)[0x612000002920]{UNUSED}: Deallocated [0;m[1;31m20180822124927916 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:139 timeslot(0-0-1-SDCCH8)[0x61200000aea0]{NOT_INITIALIZED}: Received Event TS_EV_LCHAN_UNUSED [0;m[1;32m20180822124927916 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-4)[0x6120000027a0]{UNUSED}: Terminating (cause = OSMO_FSM_TERM_REQUEST) [0;m[1;32m20180822124927916 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-4)[0x6120000027a0]{UNUSED}: Removing from parent timeslot(0-0-1-SDCCH8)[0x61200000aea0] [0;m[1;32m20180822124927916 [1;34mDCHAN[0;m[1;32m <0010> lchan_fsm.c:354 lchan(0-0-1-SDCCH8-4)[0x6120000027a0]{UNUSED}: (type=NONE) Clearing lchan state [0;m[1;32m20180822124927916 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-4)[0x6120000027a0]{UNUSED}: Freeing instance [0;m[1;32m20180822124927916 [1;34mDCHAN[0;m[1;32m <0010> fsm.c:381 lchan(0-0-1-SDCCH8-4)[0x6120000027a0]{UNUSED}: Deallocated [0;m[1;31m20180822124927916 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:139 timeslot(0-0-1-SDCCH8)[0x61200000aea0]{NOT_INITIALIZED}: Received Event TS_EV_LCHAN_UNUSED [0;m[1;32m20180822124927916 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-5)[0x612000002620]{UNUSED}: Terminating (cause = OSMO_FSM_TERM_REQUEST) [0;m[1;32m20180822124927916 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-5)[0x612000002620]{UNUSED}: Removing from parent timeslot(0-0-1-SDCCH8)[0x61200000aea0] [0;m[1;32m20180822124927916 [1;34mDCHAN[0;m[1;32m <0010> lchan_fsm.c:354 lchan(0-0-1-SDCCH8-5)[0x612000002620]{UNUSED}: (type=NONE) Clearing lchan state [0;m[1;32m20180822124927916 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-5)[0x612000002620]{UNUSED}: Freeing instance [0;m[1;32m20180822124927916 [1;34mDCHAN[0;m[1;32m <0010> fsm.c:381 lchan(0-0-1-SDCCH8-5)[0x612000002620]{UNUSED}: Deallocated [0;m[1;31m20180822124927916 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:139 timeslot(0-0-1-SDCCH8)[0x61200000aea0]{NOT_INITIALIZED}: Received Event TS_EV_LCHAN_UNUSED [0;m[1;32m20180822124927917 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-6)[0x6120000024a0]{UNUSED}: Terminating (cause = OSMO_FSM_TERM_REQUEST) [0;m[1;32m20180822124927917 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-6)[0x6120000024a0]{UNUSED}: Removing from parent timeslot(0-0-1-SDCCH8)[0x61200000aea0] [0;m[1;32m20180822124927917 [1;34mDCHAN[0;m[1;32m <0010> lchan_fsm.c:354 lchan(0-0-1-SDCCH8-6)[0x6120000024a0]{UNUSED}: (type=NONE) Clearing lchan state [0;m[1;32m20180822124927917 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-6)[0x6120000024a0]{UNUSED}: Freeing instance [0;m[1;32m20180822124927917 [1;34mDCHAN[0;m[1;32m <0010> fsm.c:381 lchan(0-0-1-SDCCH8-6)[0x6120000024a0]{UNUSED}: Deallocated [0;m[1;31m20180822124927917 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:139 timeslot(0-0-1-SDCCH8)[0x61200000aea0]{NOT_INITIALIZED}: Received Event TS_EV_LCHAN_UNUSED [0;m[1;32m20180822124927917 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-7)[0x612000002320]{UNUSED}: Terminating (cause = OSMO_FSM_TERM_REQUEST) [0;m[1;32m20180822124927917 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-7)[0x612000002320]{UNUSED}: Removing from parent timeslot(0-0-1-SDCCH8)[0x61200000aea0] [0;m[1;32m20180822124927917 [1;34mDCHAN[0;m[1;32m <0010> lchan_fsm.c:354 lchan(0-0-1-SDCCH8-7)[0x612000002320]{UNUSED}: (type=NONE) Clearing lchan state [0;m[1;32m20180822124927917 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-1-SDCCH8-7)[0x612000002320]{UNUSED}: Freeing instance [0;m[1;32m20180822124927917 [1;34mDCHAN[0;m[1;32m <0010> fsm.c:381 lchan(0-0-1-SDCCH8-7)[0x612000002320]{UNUSED}: Deallocated [0;m[1;31m20180822124927917 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:139 timeslot(0-0-1-SDCCH8)[0x61200000aea0]{NOT_INITIALIZED}: Received Event TS_EV_LCHAN_UNUSED [0;m[1;31m20180822124927917 [1;34mDTS[0;m[1;31m <0011> osmo_bsc_main.c:318 timeslot(0-0-2-TCH_F)[0x61200000ad20]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;32m20180822124927917 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-2-TCH_F-0)[0x6120000021a0]{UNUSED}: Terminating (cause = OSMO_FSM_TERM_REQUEST) [0;m[1;32m20180822124927917 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-2-TCH_F-0)[0x6120000021a0]{UNUSED}: Removing from parent timeslot(0-0-2-TCH_F)[0x61200000ad20] [0;m[1;32m20180822124927917 [1;34mDCHAN[0;m[1;32m <0010> lchan_fsm.c:354 lchan(0-0-2-TCH_F-0)[0x6120000021a0]{UNUSED}: (type=NONE) Clearing lchan state [0;m[1;32m20180822124927917 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-2-TCH_F-0)[0x6120000021a0]{UNUSED}: Freeing instance [0;m[1;32m20180822124927917 [1;34mDCHAN[0;m[1;32m <0010> fsm.c:381 lchan(0-0-2-TCH_F-0)[0x6120000021a0]{UNUSED}: Deallocated [0;m[1;31m20180822124927917 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:139 timeslot(0-0-2-TCH_F)[0x61200000ad20]{NOT_INITIALIZED}: Received Event TS_EV_LCHAN_UNUSED [0;m[1;31m20180822124927918 [1;34mDTS[0;m[1;31m <0011> osmo_bsc_main.c:318 timeslot(0-0-3-TCH_F)[0x61200000aba0]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;32m20180822124927918 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-3-TCH_F-0)[0x612000002020]{UNUSED}: Terminating (cause = OSMO_FSM_TERM_REQUEST) [0;m[1;32m20180822124927918 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-3-TCH_F-0)[0x612000002020]{UNUSED}: Removing from parent timeslot(0-0-3-TCH_F)[0x61200000aba0] [0;m[1;32m20180822124927918 [1;34mDCHAN[0;m[1;32m <0010> lchan_fsm.c:354 lchan(0-0-3-TCH_F-0)[0x612000002020]{UNUSED}: (type=NONE) Clearing lchan state [0;m[1;32m20180822124927918 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-3-TCH_F-0)[0x612000002020]{UNUSED}: Freeing instance [0;m[1;32m20180822124927918 [1;34mDCHAN[0;m[1;32m <0010> fsm.c:381 lchan(0-0-3-TCH_F-0)[0x612000002020]{UNUSED}: Deallocated [0;m[1;31m20180822124927918 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:139 timeslot(0-0-3-TCH_F)[0x61200000aba0]{NOT_INITIALIZED}: Received Event TS_EV_LCHAN_UNUSED [0;m[1;31m20180822124927918 [1;34mDTS[0;m[1;31m <0011> osmo_bsc_main.c:318 timeslot(0-0-4-TCH_F)[0x61200000aa20]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;32m20180822124927918 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-4-TCH_F-0)[0x612000001ea0]{UNUSED}: Terminating (cause = OSMO_FSM_TERM_REQUEST) [0;m[1;32m20180822124927918 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-4-TCH_F-0)[0x612000001ea0]{UNUSED}: Removing from parent timeslot(0-0-4-TCH_F)[0x61200000aa20] [0;m[1;32m20180822124927918 [1;34mDCHAN[0;m[1;32m <0010> lchan_fsm.c:354 lchan(0-0-4-TCH_F-0)[0x612000001ea0]{UNUSED}: (type=NONE) Clearing lchan state [0;m[1;32m20180822124927918 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-4-TCH_F-0)[0x612000001ea0]{UNUSED}: Freeing instance [0;m[1;32m20180822124927918 [1;34mDCHAN[0;m[1;32m <0010> fsm.c:381 lchan(0-0-4-TCH_F-0)[0x612000001ea0]{UNUSED}: Deallocated [0;m[1;31m20180822124927918 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:139 timeslot(0-0-4-TCH_F)[0x61200000aa20]{NOT_INITIALIZED}: Received Event TS_EV_LCHAN_UNUSED [0;m[1;31m20180822124927918 [1;34mDTS[0;m[1;31m <0011> osmo_bsc_main.c:318 timeslot(0-0-5-TCH_F)[0x61200000a8a0]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;32m20180822124927918 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-5-TCH_F-0)[0x612000001d20]{UNUSED}: Terminating (cause = OSMO_FSM_TERM_REQUEST) [0;m[1;32m20180822124927918 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-5-TCH_F-0)[0x612000001d20]{UNUSED}: Removing from parent timeslot(0-0-5-TCH_F)[0x61200000a8a0] [0;m[1;32m20180822124927918 [1;34mDCHAN[0;m[1;32m <0010> lchan_fsm.c:354 lchan(0-0-5-TCH_F-0)[0x612000001d20]{UNUSED}: (type=NONE) Clearing lchan state [0;m[1;32m20180822124927919 [1;34mDCHAN[0;m[1;32m <0010> timeslot_fsm.c:139 lchan(0-0-5-TCH_F-0)[0x612000001d20]{UNUSED}: Freeing instance [0;m[1;32m20180822124927919 [1;34mDCHAN[0;m[1;32m <0010> fsm.c:381 lchan(0-0-5-TCH_F-0)[0x612000001d20]{UNUSED}: Deallocated [0;m[1;31m20180822124927919 [1;34mDTS[0;m[1;31m <0011> timeslot_fsm.c:139 timeslot(0-0-5-TCH_F)[0x61200000a8a0]{NOT_INITIALIZED}: Received Event TS_EV_LCHAN_UNUSED [0;m[1;31m20180822124927919 [1;34mDTS[0;m[1;31m <0011> osmo_bsc_main.c:318 timeslot(0-0-6-PDCH)[0x61200000a720]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;31m20180822124927919 [1;34mDTS[0;m[1;31m <0011> osmo_bsc_main.c:318 timeslot(0-0-7-PDCH)[0x61200000a5a0]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;31m20180822124927919 [1;34mDTS[0;m[1;31m <0011> gsm_data.c:1321 timeslot(0-0-0-NONE)[0x61200000b020]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;31m20180822124927919 [1;34mDTS[0;m[1;31m <0011> gsm_data.c:1321 timeslot(0-0-1-NONE)[0x61200000aea0]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;31m20180822124927919 [1;34mDTS[0;m[1;31m <0011> gsm_data.c:1321 timeslot(0-0-2-NONE)[0x61200000ad20]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;31m20180822124927919 [1;34mDTS[0;m[1;31m <0011> gsm_data.c:1321 timeslot(0-0-3-NONE)[0x61200000aba0]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;31m20180822124927919 [1;34mDTS[0;m[1;31m <0011> gsm_data.c:1321 timeslot(0-0-4-NONE)[0x61200000aa20]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;31m20180822124927920 [1;34mDTS[0;m[1;31m <0011> gsm_data.c:1321 timeslot(0-0-5-NONE)[0x61200000a8a0]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;31m20180822124927920 [1;34mDTS[0;m[1;31m <0011> gsm_data.c:1321 timeslot(0-0-6-NONE)[0x61200000a720]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;31m20180822124927920 [1;34mDTS[0;m[1;31m <0011> gsm_data.c:1321 timeslot(0-0-7-NONE)[0x61200000a5a0]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;31m20180822124927920 [1;34mDTS[0;m[1;31m <0011> gsm_data.c:1321 timeslot(0-1-0-NONE)[0x61200000a2a0]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;31m20180822124927920 [1;34mDTS[0;m[1;31m <0011> gsm_data.c:1321 timeslot(0-1-1-NONE)[0x61200000a120]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;31m20180822124927920 [1;34mDTS[0;m[1;31m <0011> gsm_data.c:1321 timeslot(0-1-2-NONE)[0x612000009fa0]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;31m20180822124927920 [1;34mDTS[0;m[1;31m <0011> gsm_data.c:1321 timeslot(0-1-3-NONE)[0x612000009e20]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;31m20180822124927920 [1;34mDTS[0;m[1;31m <0011> gsm_data.c:1321 timeslot(0-1-4-NONE)[0x612000009ca0]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;31m20180822124927920 [1;34mDTS[0;m[1;31m <0011> gsm_data.c:1321 timeslot(0-1-5-NONE)[0x612000009b20]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;31m20180822124927920 [1;34mDTS[0;m[1;31m <0011> gsm_data.c:1321 timeslot(0-1-6-NONE)[0x6120000099a0]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m[1;31m20180822124927920 [1;34mDTS[0;m[1;31m <0011> gsm_data.c:1321 timeslot(0-1-7-NONE)[0x612000009820]{NOT_INITIALIZED}: Received Event TS_EV_OML_DOWN [0;m================================================================= ==17607==ERROR: AddressSanitizer: heap-use-after-free on address 0x62e000060a68 at pc 0x7f5ea8e27086 bp 0x7ffde92b6d80 sp 0x7ffde92b6d78 READ of size 8 at 0x62e000060a68 thread T0 #0 0x7f5ea8e27085 in handle_ts1_write input/ipaccess.c:371 #1 0x7f5ea8e27085 in ipaccess_fd_cb input/ipaccess.c:391 #2 0x7f5ea9147ca8 in osmo_fd_disp_fds /home/osmocom-build/jenkins/workspace/osmo-gsm-tester_build-osmo-bsc/libosmocore/src/select.c:217 #3 0x7f5ea9147ca8 in osmo_select_main /home/osmocom-build/jenkins/workspace/osmo-gsm-tester_build-osmo-bsc/libosmocore/src/select.c:257 #4 0x555813ab79d6 in main /home/osmocom-build/jenkins/workspace/osmo-gsm-tester_build-osmo-bsc/osmo-bsc/src/osmo-bsc/osmo_bsc_main.c:922 #5 0x7f5ea76d02e0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202e0) #6 0x555813ab84e9 in _start (/home/jenkins/workspace/osmo-gsm-tester_manual-run/trial-130/inst/osmo-bsc/bin/osmo-bsc+0x34d4e9) 0x62e000060a68 is located 1640 bytes inside of 48072-byte region [0x62e000060400,0x62e00006bfc8) freed by thread T0 here: #0 0x7f5eaa1eea10 in free (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1a10) #1 0x7f5ea9c1b86a in _talloc_free (/usr/lib/x86_64-linux-gnu/libtalloc.so.2+0x486a) previously allocated by thread T0 here: #0 0x7f5eaa1eed28 in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1d28) #1 0x7f5ea9c1dacd in _talloc_zero (/usr/lib/x86_64-linux-gnu/libtalloc.so.2+0x6acd) SUMMARY: AddressSanitizer: heap-use-after-free input/ipaccess.c:371 in handle_ts1_write Shadow bytes around the buggy address: 0x0c5c800040f0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd 0x0c5c80004100: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd 0x0c5c80004110: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd 0x0c5c80004120: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd 0x0c5c80004130: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd =>0x0c5c80004140: fd fd fd fd fd fd fd fd fd fd fd fd fd[fd]fd fd 0x0c5c80004150: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd 0x0c5c80004160: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd 0x0c5c80004170: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd 0x0c5c80004180: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd 0x0c5c80004190: 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 ==17607==ABORTING
The issue is in handle_ts1_write:
static int handle_ts1_write(struct osmo_fd *bfd) { struct e1inp_line *line = bfd->data; <--- HERE, line 371 return __handle_ts1_write(bfd, line); }
Which is called from:
/* callback from select.c in case one of the fd's can be read/written */ int ipaccess_fd_cb(struct osmo_fd *bfd, unsigned int what) { int rc = 0; if (what & BSC_FD_READ) rc = handle_ts1_read(bfd); if (rc != -EBADF && (what & BSC_FD_WRITE)) rc = handle_ts1_write(bfd); return rc; }
THat means some path in handle_ts1_read() freed the connection (and thus bfd) but didn't return -EBADF correctly. It must be there because otherwise the report would appear somewhere in osmo_fd_disp_fds() (in case conn was somehow freed without disarming the timer).
Files
Updated by pespin almost 6 years ago
- File trial-130-run.tgz trial-130-run.tgz added
Updated by pespin almost 6 years ago
This is the aprox call path map in related code:
osmo_fd_disp_fds ipaccess_fd_cb handle_ts1_read ipa_msg_recv_buffered recv(fd) ipaccess_rcvmsg ipa_ccm_rcvmsg_base e1i_ts->line->ops->sign_link() ipaccess_sign_link (.sign_link = ipaccess_sign_link) abis_nm_rcvmsg abis_nm_rcvmsg_fom abis_nm_rx_opstart_ack handle_ts1_write
So far the only possibility I didn't check which can potentially free the connection without returning EBADF is the path in which handle_ts1_read calls link>line->ops->sign_link().
Updated by pespin almost 6 years ago
- Status changed from New to In Progress
After following the path tree from ipaccess_sign_link, I found two places were the connecting is destroyed without returning -EBADF. These two places actually happen after a signal being dispatched, which means we probably cannot return an error from there. In that case, we need to deferr the destruction with a timer so we can destroy it without being inside osmo_fd cb.
Here's the path tree I filled manually:
osmo_fd_disp_fds ipaccess_fd_cb handle_ts1_read ipa_msg_recv_buffered recv(fd) ipaccess_rcvmsg ipa_ccm_rcvmsg_base e1i_ts->line->ops->sign_link() ipaccess_sign_link (.sign_link = ipaccess_sign_link) abis_nm_rcvmsg abis_nm_rcvmsg_fom abis_nm_rcvmsg_report abis_nm_rx_statechg_rep osmo_signal_dispatch(SS_NM, S_NM_STATECHG_OPER, &nsd); bts_ipa_nm_sig_cb nm_statechg_event abis_nm_opstart abis_nm_set_bts_attr abis_nm_chg_adm_state ipaccess_drop_oml <--------------------- THIS ONE!!!! osmo_signal_dispatch(SS_NM, S_NM_SW_ACTIV_REP, mb); bts_ipa_nm_sig_cb sw_activ_rep abis_nm_ipaccess_rsl_connect rx_fail_evt_rep handle_manufact_report log_oml_fail_rep osmo_signal_dispatch(SS_NM, S_NM_TEST_REP, mb); abis_nm_rcvmsg_sw abis_nm_tlv_parse abis_nm_nack_cause_name osmo_signal_dispatch(SS_NM, S_NM_NACK, &nack_data); nm_sig_cb oml_msg_nack ipaccess_drop_oml <--------------------- THIS ONE!!!! abis_nm_rx_chg_adm_state_ack update_admstate osmo_signal_dispatch(SS_NM, S_NM_STATECHG_ADM, &nsd); nm_statechg_event <-- this one leads to ipaccess_drop_oml, see above abis_nm_rx_sw_act_req abis_nm_sw_act_req_ack abis_nm_get_sw_conf abis_nm_select_newest_sw ipacc_sw_activate abis_nm_rx_lmt_event osmo_signal_dispatch(SS_NM, S_NM_IPACC_RESTART_ACK, NULL); osmo_signal_dispatch(SS_NM, S_NM_IPACC_RESTART_NACK, NULL); abis_nm_rx_get_attr_resp abis_nm_queue_send_next abis_nm_rx_opstart_ack osmo_signal_dispatch(SS_NM, S_NM_OPSTART_ACK, mb); bts_ipa_nm_sig_cb nm_rx_opstart_ack abis_nm_rcvmsg_manuf abis_nm_rx_ipacc abis_nm_queue_send_next abis_nm_send_msg abis_sendmsg handle_ts1_write
And here's the two places requiring fix:
diff --git a/src/osmo-bsc/bts_ipaccess_nanobts.c b/src/osmo-bsc/bts_ipaccess_nanobts.c index 80f7c9c6d..bf637d661 100644 --- a/src/osmo-bsc/bts_ipaccess_nanobts.c +++ b/src/osmo-bsc/bts_ipaccess_nanobts.c @@ -166,7 +166,7 @@ static int nm_statechg_event(int evt, struct nm_statechg_signal_data *nsd) enum abis_nm_chan_comb ccomb = abis_nm_chcomb4pchan(ts->pchan_from_config); if (abis_nm_set_channel_attr(ts, ccomb) == -EINVAL) { - ipaccess_drop_oml(trx->bts); + ipaccess_drop_oml(trx->bts); //THIS ONE! WE HAVE TO DEFERR IT SINCE WE COME FROM A SIGNAL HANDLER WHICH IN TURN COMES FROM osmo_fb cb WHICH REQUIRES RETURNING -EBADF! something like ipaccess_drop_oml_deferred return -1; } abis_nm_chg_adm_state(trx->bts, obj_class, diff --git a/src/osmo-bsc/osmo_bsc_main.c b/src/osmo-bsc/osmo_bsc_main.c index 8ff0e8aa3..13e72d399 100644 --- a/src/osmo-bsc/osmo_bsc_main.c +++ b/src/osmo-bsc/osmo_bsc_main.c @@ -191,7 +191,7 @@ static int oml_msg_nack(struct nm_nack_signal_data *nack) } if (is_ipaccess_bts(nack->bts)) - ipaccess_drop_oml(nack->bts); + ipaccess_drop_oml(nack->bts); //NEEDS FIX!!!!!!! DEFERR!!! return 0; }
Updated by pespin almost 6 years ago
TODO: Not directly related to this crash, but I see that "sign_link_down" (through ipaccess_sign_link_down) and "sign_link_up" (through ipaccess_sign_link_up) also can call ipaccess_drop_oml and not return NULL (in ipaccess_rcvmsg and in ipaccess_bts_read_cb), which means read_cb won't return -EBADF and we'll have a heap-use-after-free.
For down, check:- ipaccess_bts_updown_cb
- ipaccess_drop
That means, actually that we may need to add the -EBADF check in libosmo-abis (ipa_client_fd_cb) in:
case IPA_CLIENT_LINK_STATE_CONNECTED: if (what & BSC_FD_READ) { LOGIPA(link, LOGL_DEBUG, "connected read\n"); ipa_client_read(link); } if (what & BSC_FD_WRITE) { LOGIPA(link, LOGL_DEBUG, "connected write\n"); ipa_client_write(link); }
We need to check in that case if ipa_client_read() can close the "link" ptr.
Updated by pespin almost 6 years ago
- % Done changed from 0 to 50
I pushed a potential fix for the reported crash in "pespin/fix-oml-asan". I'll test it soon in osmo-gsm-tester.
TODO: look at the sign_link_down/up stuff.
Updated by pespin almost 6 years ago
Reported issue fixed in: https://gerrit.osmocom.org/#/c/osmo-bsc/+/10578/
TODO: look at the sign_link_down/up stuff.
Updated by pespin almost 6 years ago
TODO: look at the sign_link_down/up stuff.
Another TODO: backport https://gerrit.osmocom.org/#/c/osmo-bsc/+/10578/ to openbsc once it has been reviewed.
Updated by pespin almost 6 years ago
- % Done changed from 50 to 80
Submitted more related patches for the missing code paths, this time in ipa_client and ipa_server_conn:
remote: https://gerrit.osmocom.org/#/c/libosmo-abis/+/10656 ipa: Simplify code in ipa_client_read remote: https://gerrit.osmocom.org/#/c/libosmo-abis/+/10657 ipa: Simplify code in ipa_server_conn_read remote: https://gerrit.osmocom.org/#/c/libosmo-abis/+/10658 ipa: Allow signalling fd destroyed in ipa_client_read remote: https://gerrit.osmocom.org/#/c/libosmo-abis/+/10659 ipa: Allow signalling fd destroyed in ipa_server_conn_read remote: https://gerrit.osmocom.org/#/c/libosmo-abis/+/10660 ipaccess: Return -EBADF when closing socket in ipaccess_bts_read_cb remote: https://gerrit.osmocom.org/#/c/libosmo-abis/+/10661 ipaccess: Allow passing return code in e1inp_line_ops->sign_link()
TODO: backport https://gerrit.osmocom.org/#/c/osmo-bsc/+/10578/ to openbsc once it has been reviewed.
Updated by pespin almost 6 years ago
- Status changed from In Progress to Feedback
- % Done changed from 80 to 90
Backport submitted here:
https://gerrit.osmocom.org/#/c/openbsc/+/10665 Fix heap-use-after-free due to OML link destruction
Updated by pespin almost 6 years ago
- Status changed from Feedback to Resolved
- % Done changed from 90 to 100
Merged, closing.