Summary:	ASTERISK-19796: race between ast_readaudio_callback and ast_closestream
Reporter:	Marcus Hunger (fnordian)	Labels:
Date Opened:	2012-04-26 07:11:13	Date Closed:	2012-06-06 10:30:39
Priority:	Minor	Regression?
Status:	Closed/Complete	Components:	Core/Channels
Versions:	10.3.0	Frequency of Occurrence	Occasional
Related Issues:
Environment:		Attachments:	( 0) diff.txt ( 1) lockfix.patch
Description:	When a stream is closed while ast_read calls ast_fsread_audio by a channels timingfunc there might happen an access to an already freed datastructure (ast_filestream). This can happen because the channel is unlocked before the callback is called. You can observe this using valgrind: ==2737== Invalid read of size 8 ==2737==    at 0x4E2BE0: ast_readaudio_callback (file.c:821) ==2737==    by 0x4E2E1A: ast_fsread_audio (file.c:868) ==2737==    by 0x47D9BD: __ast_read (channel.c:3871) ==2737==    by 0x47FB58: ast_read (channel.c:4310) ==2737==    by 0x47CFCB: ast_waitfordigit_full (channel.c:3597) ==2737==    by 0x47CC6A: ast_waitfordigit (channel.c:3530) ==2737==    by 0x45495B: bridge_channel_feature (bridging.c:829) ==2737==    by 0x45566E: bridge_channel_join (bridging.c:993) ==2737==    by 0x455FFB: ast_bridge_join (bridging.c:1105) ==2737==    by 0x1124E241: confbridge_exec (app_confbridge.c:1523) ==2737==    by 0x528BEE: pbx_exec (pbx.c:1551) ==2737==    by 0x533B31: pbx_extension_helper (pbx.c:4396) ==2737==  Address 0x923d290 is 704 bytes inside a block of size 860 free'd ==2737==    at 0x4C21710: free (vg_replace_malloc.c:427) ==2737==    by 0x449297: __ast_free_region (astmm.c:192) ==2737==    by 0x449698: __ast_free (astmm.c:226) ==2737==    by 0x44AB47: internal_ao2_ref (astobj2.c:279) ==2737==    by 0x44AA36: __ao2_ref (astobj2.c:237) ==2737==    by 0x4E3174: ast_closestream (file.c:973) ==2737==    by 0x4E0BC9: ast_stopstream (file.c:132) ==2737==    by 0x4E411E: waitstream_core (file.c:1276) ==2737==    by 0x4E4900: ast_waitstream (file.c:1398) ==2737==    by 0x4E4AA4: ast_stream_and_wait (file.c:1430) ==2737==    by 0x11252534: playfile_thread (app_confbridge.c:2719) ==2737==    by 0x5963B3: dummy_start (utils.c:1010) Moving the unlock so it is after the call to timingfunc seems to fix this.
Comments:	By: Matt Jordan (mjordan) 2012-04-30 08:42:18.521-0500 Moving this unlock changes the locking model for users of ast_settimeout, which includes generators.  This may not be the correct solution; however, that doesn't change the fact that the race condition exists.  Thanks for reporting this. By: Terry Wilson (twilson) 2012-06-05 13:39:39.342-0500 What is this playfile_thread function I see in the valgrind output? From what I can tell, this function has never existed in Asterisk. By: Terry Wilson (twilson) 2012-06-05 16:51:20.856-0500 I haven't really thought much about whether or not bumping the ref on data in the case of where chan->timingdata == chan will cause problems or not (sample calls seemed to work fine), but we do need to bump the refcount if we are storing an ast_filestream on the channel. So, something like diff.txt might work, but also might need to be fleshed out into a more complete solution. By: Marcus Hunger (fnordian) 2012-06-06 04:00:07.961-0500 playfile_thread is a proprietary function added by us. it has been removed already in favour of a generator. when posting the bug i wasn't aware it was involved. if you can't see a problem here, i am very so i've bothered. By: Terry Wilson (twilson) 2012-06-06 10:30:39.461-0500 I'm going to go ahead and close the issue since it looks like the bug depends upon a proprietary addition. If you run across the issue with unmodified Asterisk, please feel free to open a new issue. Thanks!