recent_logfile() causes a huge memory leak for large log files

My system is completely unusable while apport runs because of it's rampant memory consumption.

I tried this under a current amd64 live desktop system in a VM with 1 GB RAM, and "apport-bug linux" works just fine. ps reports 513 MB VSZ and 63 MB RSS which certainly is more than it could be, but far from unreasonable. gedit (which is a C GTK program) uses almost the same VSZ (496 MB) and 25 MB RSS.

So let's dissect when things go wrong at your end. Does it only happen with the linux hook, or does it affect other packages as well? I. e. does "apport-bug coreutils" have that problem? (that does not have any package hooks). If not, does "apport-bug udisks" have? (that does some extra stuff).

Thanks!

Actually, now that I've dug a little further, this is still probably a bug, but not in the way I originally thought.

Can you confirm my guess that when apport runs and starts gathering logs, it actually reads those logs into memory in some manner?

What I discovered while looking at a completely different issue is that /var/log/syslog was 3.8GB in size. So now I'm thinking that the memory errors in the apport trace are due to apport simply trying to read that into memory and then dying horribly when it runs out of available memory.

What happened to expose this was this bug: #984273 which triggered a massive flood (several million lines of repeated messages) into syslog, causing it to grow in size almost instantly. At this point, logrotate has moved the 3.8+GB log out so if I run apport-bug at this point, I should be fine. I'll do so now to verify this is the case.

Ah, a huge log file would indeed explain this, thanks!

So I guess the failure during /usr/share/apport/dump_acpi_tables.py was a red herring, and it already used up all available memory before.

I let /var/log/syslog grow massively with

$ yes 'Apr 20 11:30:00 donald kernel: bogus message' | sudo tee -a /var/log/syslog >/dev/null

and ^Ced after it readed a Gigabyte. Running "apport-bug linux" then reproduces the bug.

The faulty function is attach_wifi() in /usr/share/apport/package-hooks/source_linux.py, which calls

  report['WifiSyslog'] = recent_syslog(re.compile(r'(NetworkManager|modem-manager|dhclient|kernel|wpa_supplicant)(\[\d+\])?:'))

and recent_syslog() has no rate limit.

Fixed in trunk r2295.

Hello Jeff, or anyone else affected,

Accepted apport into precise-proposed. The package will build now and be available in a few hours. Please test and give feedback here. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Thank you in advance!

Martin, yeah, after I started looking into the other bug (among other things) is when I noticed finally that syslog was that big. After logrotate had moved the log on (and I'd made a snapshot of it just in case :) ) I did verify that apport was functioning fine with more reasonable sized log files.

So that led me to think, perhaps apport should have a prompt to let the submitter know that a log file is above a certain size... I don't know if that would be an arbitrary size or perhaps a calculated percentage of available RAM, and then warn the user that the log file is too big, and provide a mechanism to skip the upload of that one file.

Perhaps that could provide a message that would point the user to the specific file being skipped and maybe the advice to copy the log and trim out unnecessary stuff before manually adding it to the bug the user opened.

Anyway, it was a thought I had... not sure if what I encountered is something that would be encountered often enough to make that added functionality worthwhile... though I CAN easily see this being a good idea for some things, like .xsession-errors. On my system with the nVidia GT240M card, I have to routinely delete .xsession-errors as it very quickly grows to hundreds of gigabytes in size. It got to the point where I just had cron delete the file every week. Anyway, I digress, that was but an example.

Ok... so disregard my last comment thoughts. I actually sat down and decided to look at adding what I had suggested to apport and actually looked at the change made to resolve this bug. Thanks for the quick resolution, and I'm glad my weird situation was able to help make apport a little better :)

Jeff, would you be able to test the version in -proposed? You can recreate the situation given the test case in comment 7. (We need verification for SRUs). Thanks!

Had to update python-apport as well as apport, but after doing so, using pitti's recreation steps above I was not able to trigger a failure.

I didn't actually file the fake kernel bug, but apport no longer crashes while parsing my giant syslog file. So I'd say it appears to be resolved in proposed!

This bug was fixed in the package apport - 2.0.1-0ubuntu6

---------------
apport (2.0.1-0ubuntu6) precise-proposed; urgency=low

  * Cherry-pick from trunk:
    - hookutils.py, recent_logfile(): Use a default limit of 10000 lines and
      call "tail" instead of reading the whole file. This protects against
      using up all memory when there are massive repeated log messages.
      (LP: #984256)
    - apport-gtk: Do not assume that an icon requested for size 42 actually
      delivers size 42; some themes do not have this available and deliver a
      smaller one instead, causing overflows. Also, copy the image as
      gtk_icon_theme_load_icon() returns a readonly result which we must not
      modify. Fixes crashes when using themes other than the standard Ubuntu
      ones. (LP: #937249)
 -- Martin Pitt <email address hidden> Fri, 20 Apr 2012 18:53:24 +0200