Continuous music playback causes dramatic RAM usage

[dsuden]

Building up a playlist of songs and leaving it running in Haiku results in a memory leak that could flood a medium sized village within a day. :-) I assume, from the behavior I'm seeing, that each time a new song starts, it leaks a bit more RAM. After 24 hours, I've seen memory consumption over 400MB, and it just keeps going up, the longer the program (MediaPlayer or SoundPlay) is left open and running song after song. This is a serious problem for anyone (like me) who needs the OS to play music for days, weeks, or longer, nonstop.

[diver]

Which process consumes memory? MediaPlayer? Take a screenshot of ProcessController.

[cocobean]

Tested: hrev52013 x86_64

Monitored with ProcessController - Memory Usage -> MediaPlayer

MediaPlayer gains about 3MB/hour of consistent audio playback time. App errors/warnings show specific buffer(s) being filled up, but not released umtil application start/exit - not refreshing buffers between each playlist entry or playlist loop.

[Barrett]

This is the usual buffer management issue, or at least related to it.

I've been working on that, and I had a WIP, I even offered my help to someone and I was gifted with being accused (once again) for introducing a bug which was there at least 6 years before I even had commit access. The result of how the thing has been handled, is that I'm not going to contribute any information about the resolution of any media kit bug. I just can't continue to bear the situation.

I'm not even an Haiku developer anymore, so there's no hope I will fix that.

[leavengood]

I am now looking at these sorts of issues.

[ttcoder]

Thanks for looking at this one Ryan

This one's easy to setup a test for (just launch MediaPlayer with a big playlist) though it takes time to build up heap consumption

(with a bit of luck, maybe the "time consuming" part can be eliminated by building/releasing a BMediaFile+BMediaTrack pair at full speed a thousand time? see e.g. the .cpp code in #9945 and #11752)

Very curious to see if my patch changes the leak figures, i.e. if less heap is leaked after 1000 iterations.

(EDIT: as to leaked buffers, that's a different/unrelated bug, relating to areas rather than heap, and which I believe was fixed in #14755 thx Ryan for that one)

[ttcoder]

In recent hrevs I'm unable to work on this, as leak_analyser.sh no longer works.

I've been told to upgrade to a recent hrev, as media leaks are reportedly fixed there. We know our apps still leak, so I need to validate that assessment, or find out /who/ is leaking, if not media -- but I'm unable to, as the guarded heap no longer outputs *anything* at all on exit, so leak_analyser.sh has nothing to analyse.

That problem has been confirmed by mmlr, who points the finger at changes in runtime_loader (?)

We've been stuck for weeks on this.. Looks like another cycle of "let it rot" is starting for us..

[mmlr]

Specifically 354b60af29b2cb24d8d02265f83e44c9bfdf8005 as part of hrev52813 breaks the dump on exit feature (which is called from __heap_terminate_after, which is called from terminate_after of libroot_debug). The breakage is not obvious to me, since this should now simply be called from the runtime_loader directly, but it is now not called at all. Whether or not this is related to libroot_debug usually being loaded using LD_PRELOAD, I have not been able to test due to severe time constraints.

[waddlesplash]

Well, I am pretty sure leavengood was using the leak analyser recently, so I'm mildly surprised it doesn't work... Maybe I'm mistaken and he wasn't using it.

[ttcoder]

Confirming : Working with CC6, on

	Haiku shredder 1 hrev53561 Oct 23 2019 18:23:49 x86_64 x86_64 Haiku

I get no output using the guarded heap the normal way; I've had to hardcode a call to

	heap_debug_dump_allocations(false, -1);

at the end of main() as a work-around. That plus a couple other factors caused a little bit of time consuming trouble, but in the end mmlr's workaround helped me to get back on track until runtime_loader is fixed.

Now that I get to analyse the leaks again, things get interesting: there is almost zero incremental leaking when CC6 goes from one mp3 to the next (just an 80-something leak, discussed with mmlr as being completely harmless to our use-case). So I have to coordinate with Dane, see if he still gets MBs/day leaks or not, and if so, why I don't see that here (at least with the guarded heap and the work-around and my audio setup).

P.S. -- for Ryan I only have his public ticket stuff and emails to go by, and judging by those he kept mentioning how leak_analyser.sh didn't work for him, and he'd need to submit a patch to review.haiku-os.org that implements the guarded heap another way; now I'm starting to wonder if what he was seeing, was actually the same runtime_loader bug we're discussing above ? If so, a bit of a shame that he wasted his time looking at a different way, when it was just a matter of fixing the runtime_loader bug to start with ? This probably warrants further investigation *g*

[ttcoder]

After a few days of realistic testing with a recent x64 hrev (at last, yay!) it's starting to look like the leaks only occur in error cases.

So we'll probably end up closing this ticket as fixed and opening a new one titled "BMediaFile leaks big time on unsupported or inexistant audio files".

EDIT:

After a quick glance at ​https://git.haiku-os.org/haiku/tree/src/add-ons/media/plugins/ffmpeg/AVFormatReader.cpp?id=9b3aa126bad2698223efd8bb5b5869cabee5e8de#n264

I see that the "if (avformat_open_input...)" case calls av_free(),

whereas the "if (avformat_find_stream_info...)" case does NOT call av_free()..

Is that significant ?

[mmlr]

The problem was the buffer of the IO context. It needs to be freed manually, but this wasn't done in the error path of avformat_open_input. Since it also resets the fIOContext to NULL, the destructor would then also not free it. This should be fixed in hrev53640.

The resulting leak here would be very variable in size, since avformat_open_input may reallocate the buffer to make it larger. In my testing, it easily consumed multiple megabytes depending on what input you fed. So even though the initial allocation is relatively small at 32K, the eventual leak could be orders of magnitude larger.

[ttcoder]

Feels good closing this, thanks much :-)

Dane did a genuine before-and-after, so that we're confident about this: he setup a playlist with intentional "404" files, and let it run with the previous hrev: mem usage creeping up. Next he ugpraded the hrev, and resumed automation: mem usage in CC6 has not budged an inch. Looks like we are as leak-free as can realistically be, at last.

/me redirects his prayers towards media_addon_server et al

[leavengood]

Sorry I dropped off the radar for a while for Haiku development. Work changes, etc. I was always suspicious the leak was in ffmpeg but hadn't narrowed it down yet. Though I'll do some testing again in the same way I did before to ensure I don't see the same leaking. It was pretty bad though, and would happen on normal files so I can't know without testing that this fixed the issue.

[ttcoder]

Well... teamwork ! It makes sense to share the workload, and that way you shared credit ;-) (BBuffer fix credit goes to you; ffmpeg fix credit goes to Michael; we went AHCI thanks to waddlesplash ..etc). I'm still a bit anxious for the leak_analyser to get fixed though (as per comment:9 re runtime_loader), if only to make sure that no one else will get bitten like you were... And in case I myself have more leaks to hunt for in the future. Might ping waddleslplash in a few weeks about it when the dust settles (we're in the process of taming media_addon_server, finding new hardware, and almost returning to production). Agreed it's good to test with both leak_analyser.sh and plain-old-looking at ProcessController's memory gauges too, as a "final word" to restore peace of mind. In Dane's testing (looking at the gauges) we are leak free.

[waddlesplash]

The breakage is not obvious to me, since this should now simply be called from the runtime_loader directly, but it is now not called at all.

Fixed in hrev53886. ttcoder, please open a ticket instead of commenting about issues on unrelated tickets, though. :)

[ttcoder]

Yeah I planned to get around to it eventually, it's just that everybody has so much on their plates these days, didn't want to risk upsetting priorities.. :-]. Thanks for circling back to that one!

[waddlesplash]

Reporting a bug that exists never "upsets priorities"; we will simply mark it as "low priority" if it really is unimportant. We don't want things to get lost.

[nielx]

Assign tickets with status=closed and resolution=fixed within the R1/beta2 development window to the R1/beta2 Milestone