GNOME Bugzilla – Bug 748608
cairo_t/surface leak on gaussian filters
Last modified: 2015-08-05 11:17:00 UTC
I copied 1.1 GB of Clipart, from external USB drive, to Internal drive. Tracker-extract used all my memory, 8 GB, and swap got used, rendering my Computer almost responseless. I had to kill it. Any time i let it run again, it starts all over again. I was setting tracker to only run when idle, but tracker-extract keep on running while i work, and i had to kill it again.
Thanks for the bug report, I need a bit more information though. You mention the total size of the transfer, but I would need to know: - The total amount of files, you mention it's clipart, that suggests tiny files, spread over 1.1GB, I guess that amounts for "a lot of files". In git master, tracker-extract has made great improvements to memory usage in situations where plenty of files are scheduled for extraction of a sudden (like copy operations usually trigger). - The file format of the files being transferred, were those more or less homogeneous? If possible I would need a sample file and/or the outputs of the "file" and "gvfs-info" command line tools on those files. I would need all of this info in order to start investigating whether we're dealing with a memory leak specific to clipart images, or this is an already solved issue.
Created attachment 308618 [details] Screenshot of memory usage I am having the same/similar issue on Fedora 22 with tracker 1.4.0. After a reset of the tracker database, tracker is unable to finish indexing because all my memory are used. As long as the kernel kills the tracker-extract process. After 17 minutes of uptime - the computer is unusable. This are the log entries in journalctl -xb Aug 01 14:35:02 pc kernel: [17678] 1000 17678 121065 0 78 3 679 0 tracker-miner-u Aug 01 14:35:02 pc kernel: [17681] 1000 17681 162997 1801 107 3 12884 0 tracker-store Aug 01 14:35:02 pc kernel: [17694] 1000 17694 303273 2516 116 4 5014 0 tracker-miner-f Aug 01 14:35:02 pc kernel: [17700] 1000 17700 3837147 1843258 6400 18 1244112 0 tracker-extract Aug 01 14:35:02 pc kernel: [17716] 1000 17716 274753 1 97 4 829 0 tracker-miner-a Aug 01 14:35:02 pc kernel: [17760] 1000 17760 31101 233 16 3 30 0 htop Aug 01 14:35:02 pc kernel: Out of memory: Kill process 17700 (tracker-extract) score 887 or sacrifice child Aug 01 14:35:02 pc kernel: Killed process 17700 (tracker-extract) total-vm:15348588kB, anon-rss:7373032kB, file-rss:0kB A Screenshot about the memory usage is attached. Please, let me know, what inforamtion you need to solve this issue.
Hi Stefan, for a short while, we've stopped using memory checking APIs for tracker-extract because it was causing too many false positives (e.g. extracting data from a huge PDF could use a lot of memory). This would be down to the libraries we use to extract that data and they may or may not be broken. In most cases memory use like this is due to either: a) a corrupt non-standardised file being indexed b) the library we're using to index the file is broken or has a bug. (b) tends to be the most common case. There are tips on how to debug Tracker here: https://wiki.gnome.org/Projects/Tracker/Documentation/Debugging But ultimately, we need to know what *file(s)* is/are being indexed that causes that memory use. You can do this a number of ways: $ tracker daemon -t # Stop daemons $ /usr/libexec/tracker-extract -v 3 # Run tracker-extract separately $ tracker daemon -s # Start daemons This should at least show you the output of tracker-extract as it runs and it should drop out to the terminal when systemd/kernel kills it. Then you could send us the log. You can also send us the output of: $ tracker status --collect-debug-info That should give us some further information about your system. Thanks :)
I've added a section about this to the documentation now. We get this question a lot: https://wiki.gnome.org/Projects/Tracker/Documentation/Debugging#High_memory_use.3F
Additionally to that information, would be great if you tried beforehand with tracker 1.5.x, the only known cause of unbound memory growth in tracker-extract has been fixed there. the steps to run tracker-extract separately that Martyn posted in comment #3 might also give a good hint of what's going on, amongst the (very verbose) logs, you should identify the files it processes, there's probably 3 possible outcomes: - if it seems to be processing the same files over and over in loops, it would be most definitely a tracker-extract bug. - if it gets apparently stuck on a file, but cpu/memory usage keep hitting, it would be specific to the handling of said file, the file being corrupt, etc... in that case it would be really appreciated if you submitted the file to us. - if it's apparently processing things correctly (none of the above happen), but memory keeps growing until this situation happens, then it is most definitely fixed in 1.5.x. FWIW, tracker 1.5.1 is already on rawhide, you might try to upgrade tracker specifically.
I've tried tracker 1.5.1 from rawhide with no luck. It is still eating all my memory. Aug 02 19:01:50 pc kernel: Out of memory: Kill process 2630 (tracker-extract) score 888 or sacrifice child Aug 02 19:01:50 pc kernel: Killed process 2630 (tracker-extract) total-vm:15407904kB, anon-rss:7225160kB, file-rss:0kB Next, I will try to identify, if there's a specific file causing this problem
Thanks, keep in mind it might also be the accumulated effect of many files triggering the same extractor module (and memory leak), the amount of file(type)s as known to tracker can be obtained through `tracker status --collect-debug-info`, so that info is still appreciated. If valgrind proves too challenging or doesn't point to anything obvious, another option is moving files in/out the /usr/share/tracker/extract-rules/ or /usr/lib64/tracker-1.0/extract-modules. The former directory contains the rule files that tell which mimetype uses which extract module, and the latter contains the extract modules themselves. The net effect would be the same, you can selectively disable modules and narrow down the one that's leaking, this would give us a nice starting point to track the leak.
It seems, that SVG files are the root of my problem Steps to reproduce * Use tracker-preferences to set the locations only to ~/trackerTestDir with recurse checkbox enabled * put "adwaita-icon-theme-3.14.1" inside ~/trackerTestDir Then run tracker * tracker daemon -t * /usr/libexec/tracker-extract -v 3 At some point, the memory starts growing continuously. And during adwaita-icon-theme-3.14.1/src/fullcolor/folders.svg, all my physical memory was used. The worst files seems to be * adwaita-icon-theme-3.14.1/src/fullcolor/faces-2.svg * adwaita-icon-theme-3.14.1/src/fullcolor/printers.svg * adwaita-icon-theme-3.14.1/src/fullcolor/folders.svg I am sure, you know where to get adwaita-icon-theme :-) The link is just for your convenience http://ftp.gnome.org/pub/gnome/sources/adwaita-icon-theme/3.14/adwaita-icon-theme-3.14.1.tar.xz I have changed the settings back to my original one and added "*.svg" to the global patterns to ignore. After this, all works fine. The work was done in a few minutes and without noticeable memory usage Tracker indexed 49100 files in 5214 folders If you still need any logs or information - please let me know
Thanks so much for the investigation! I can indeed reproduce here, the cause of the leaks seems to be in librsvg (triggered by gstreamer, which expands the image in memory), I'm moving there and attaching a patch. A sample from valgrind output: ==24398== 27,976,224 (25,344 direct, 27,950,880 indirect) bytes in 66 blocks are definitely lost in loss record 9,321 of 9,324 ==24398== at 0x4A06C50: malloc (in /usr/lib64/valgrind/vgpreload_memcheck-amd64-linux.so) ==24398== by 0x18EE1622: _cairo_image_surface_create_for_pixman_image (cairo-image-surface.c:184) ==24398== by 0x18EE19C8: _cairo_image_surface_create_with_pixman_format (cairo-image-surface.c:353) ==24398== by 0x18C83F2B: _rsvg_image_surface_new (rsvg-filter.c:160) ==24398== by 0x18C8B76F: rsvg_filter_primitive_gaussian_blur_render (rsvg-filter.c:1879) ==24398== by 0x18C8DD25: rsvg_filter_primitive_render (rsvg-filter.c:86) ==24398== by 0x18C8DD25: rsvg_filter_render (rsvg-filter.c:517) ==24398== by 0x18C9CB0D: rsvg_cairo_pop_render_stack (rsvg-cairo-draw.c:806) ==24398== by 0x18C9CB0D: rsvg_cairo_pop_discrete_layer (rsvg-cairo-draw.c:853) ==24398== by 0x18C9D581: rsvg_cairo_render_path (rsvg-cairo-draw.c:553) ==24398== by 0x18C99DA1: rsvg_render_path (rsvg-base.c:2024) ==24398== by 0x18C91A4D: rsvg_node_draw (rsvg-structure.c:69) ==24398== by 0x18C91AD2: _rsvg_node_draw_children (rsvg-structure.c:87) ==24398== by 0x18C91A4D: rsvg_node_draw (rsvg-structure.c:69) ==24398== by 0x18C91AD2: _rsvg_node_draw_children (rsvg-structure.c:87) ==24398== by 0x18C91A4D: rsvg_node_draw (rsvg-structure.c:69) ==24398== by 0x18C91E62: rsvg_node_svg_draw (rsvg-structure.c:323) ==24398== by 0x18C91A4D: rsvg_node_draw (rsvg-structure.c:69) ==24398== by 0x18C9E192: rsvg_handle_render_cairo_sub (rsvg-cairo-render.c:225) ==24398== by 0x18A70AA9: gst_rsvg_decode_image (gstrsvgdec.c:238) ==24398== by 0x18A71041: gst_rsvg_dec_handle_frame (gstrsvgdec.c:342) ==24398== by 0x16A86A65: gst_video_decoder_decode_frame (gstvideodecoder.c:3317) ==24398== by 0x16A8ECF1: gst_video_decoder_have_frame (gstvideodecoder.c:3249) ==24398== by 0x16A89A45: gst_video_decoder_parse_available (gstvideodecoder.c:957) ==24398== by 0x16A89BF3: gst_video_decoder_chain_forward (gstvideodecoder.c:2115) ==24398== by 0x16A8B7AF: gst_video_decoder_chain (gstvideodecoder.c:2411) ==24398== by 0x1653ACB0: gst_pad_chain_data_unchecked (gstpad.c:4038) ==24398== by 0x1653C966: gst_pad_push_data (gstpad.c:4282) ==24398== by 0x171AAE51: gst_type_find_element_loop (gsttypefindelement.c:1127) ==24398== by 0x1656B820: gst_task_func (gsttask.c:331) ==24398== by 0x5F9D03D: g_thread_pool_thread_proxy (gthreadpool.c:307) ==24398== by 0x5F9C6B4: g_thread_proxy (gthread.c:764) That said, I noticed that even though gstreamer is able to deal with SVGs, it won't extract any useful information to tracker. Relevant to images, the gstreamer based module will fetch width/height/aspect ratio/geolocation... none of those are meaningful to svgs, and we could avoid the cpu/memory usage entirely, I'll be fixing that on the Tracker side.
Created attachment 308640 [details] [review] bgo#748608 - Destroy cairo_t after use Otherwise the cairo_t, and the surface it's created on are leaked.
This patch improves things greatly: Before: -------------------------------------------------------------------------------- Command: /home/pacaud/Sources/librsvg/.libs/lt-rsvg-convert -f png -o test.png ../lasem/tests/data/svg/samples/big/antique.svg Massif arguments: --heap=yes --depth=50 --detailed-freq=1 ms_print arguments: massif.out.30675 -------------------------------------------------------------------------------- MB 308.4^ @ | @@@#@@ | @@@@@#@@ | @@@ @@@#@@ | @@@@@@@ @@@#@@ | @@@ @@@@@ @@@#@@ | @@@@@@@@ @@@@@ @@@#@@ | @@@@@@@ @ @@@ @@@@@ @@@#@@ | @@@@@@@ @ @@@ @ @@@ @@@@@ @@@#@@ | @@@@@@@@ @@ @@ @ @@@ @ @@@ @@@@@ @@@#@@ | @@@@ @@ @@@ @@ @@ @ @@@ @ @@@ @@@@@ @@@#@@ | @@@ @@ @@ @@@ @@ @@ @ @@@ @ @@@ @@@@@ @@@#@@ | @@@@@@@ @@ @@ @@@ @@ @@ @ @@@ @ @@@ @@@@@ @@@#@@ | @@@@@@ @@@ @@ @@ @@@ @@ @@ @ @@@ @ @@@ @@@@@ @@@#@@ | @@@@@ @@@ @@@ @@ @@ @@@ @@ @@ @ @@@ @ @@@ @@@@@ @@@#@@ | @@@@@@@@@@ @@@ @@@ @@ @@ @@@ @@ @@ @ @@@ @ @@@ @@@@@ @@@#@@ | @@@@@@@ @@@@@ @@@ @@@ @@ @@ @@@ @@ @@ @ @@@ @ @@@ @@@@@ @@@#@@ | @@@@ @@@@@ @@@@@ @@@ @@@ @@ @@ @@@ @@ @@ @ @@@ @ @@@ @@@@@ @@@#@@ | @@@@@ @ @@@@@ @@@@@ @@@ @@@ @@ @@ @@@ @@ @@ @ @@@ @ @@@ @@@@@ @@@#@@ | @@@@ @@@ @ @@@@@ @@@@@ @@@ @@@ @@ @@ @@@ @@ @@ @ @@@ @ @@@ @@@@@ @@@#@@ 0 +----------------------------------------------------------------------->Gi 0 65.70 Now: -------------------------------------------------------------------------------- Command: /home/pacaud/Sources/librsvg/.libs/lt-rsvg-convert -f png -o test.png ../lasem/tests/data/svg/samples/big/antique.svg Massif arguments: --heap=yes --depth=50 --detailed-freq=1 ms_print arguments: massif.out.31604 -------------------------------------------------------------------------------- MB 15.63^ # | # | # | # |@@@@@@@@@@@@ @@#@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |@@@@@ @@@@@@ @@#@@@@@@@@@@@ @@@ @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |@@@@@ @@@@@@ @@#@@@@@@@@@@@ @@@ @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |@@@@@ @@@@@@ @@#@@@@@@@@@@@ @@@ @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |@@@@@ @@@@@@ @@#@@@@@@@@@@@ @@@ @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |@@@@@ @@@@@@ @@#@@@@@@@@@@@ @@@ @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |@@@@@ @@@@@@ @@#@@@@@@@@@@@ @@@ @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |@@@@@ @@@@@@ @@#@@@@@@@@@@@ @@@ @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |@@@@@ @@@@@@@@@#@@@@@@@@@@@ @@@ @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |@@@@@ @@@@@@@@@#@@@@@@@@@@@ @@@ @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |@@@@@ @@@@@@@@@#@@@@@@@@@@@ @@@ @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |@@@@@ @@@@@@@@@#@@@@@@@@@@@ @@@ @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |@@@@@ @@@@@@@@@#@@@@@@@@@@@ @@@ @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |@@@@@ @@@@@@@@@#@@@@@@@@@@@ @@@ @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |@@@@@ @@@@@@@@@#@@@@@@@@@@@ @@@ @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ |@@@@@ @@@@@@@@@#@@@@@@@@@@@ @@@ @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 0 +----------------------------------------------------------------------->Gi 0 65.70
Review of attachment 308640 [details] [review]: Looks obviously correct to me.
There's another leaked cairo context in the same file, around line 1752. Might want to fix that too
Just a cross reference to fedoras bug report https://bugzilla.redhat.com/show_bug.cgi?id=1198023
Created attachment 308741 [details] [review] filter: Plug one more cairo context/surface leak
Created attachment 308742 [details] [review] filter: Plug gaussian convolution matrix leak The convolution matrix on the Y axis is leaked.
Created attachment 308743 [details] [review] filter: Plug a leak
(In reply to Matthias Clasen from comment #13) > There's another leaked cairo context in the same file, around line 1752. > Might want to fix that too Right, well spotted. Attached a patch for that one and for other minor leaks I caught in the valgrind background noise, others in gstreamer left to investigate...
Review of attachment 308741 [details] [review]: yes
Review of attachment 308640 [details] [review]: lets get these committed before the moment passes
Review of attachment 308742 [details] [review]: this one looks correct too
Review of attachment 308743 [details] [review]: ok
Attachment 308640 [details] pushed as 94c4859 - bgo748608 - Destroy cairo_t after use Attachment 308741 [details] pushed as e9fa71c - filter: Plug one more cairo context/surface leak
Pushed now everything. The leak is gone, fixes to Tracker and gstreamer are still pending though, I'll take these to separate bugs if needed. Attachment 308742 [details] pushed as 2cb6d51 - filter: Plug gaussian convolution matrix leak Attachment 308743 [details] pushed as e398354 - filter: Plug a leak
(In reply to Carlos Garnacho from comment #24) > Pushed now everything. The leak is gone, fixes to Tracker and gstreamer are > still pending though, I'll take these to separate bugs if needed. Hey Carlos, you believe there is still a Tracker bug to fix here? Or you will open any further related bugs for Tracker separately? Thanks again for the fixes, reviews and investigation guys! :)
(In reply to Martyn Russell from comment #25) > (In reply to Carlos Garnacho from comment #24) > > Pushed now everything. The leak is gone, fixes to Tracker and gstreamer are > > still pending though, I'll take these to separate bugs if needed. > > Hey Carlos, you believe there is still a Tracker bug to fix here? Or you > will open any further related bugs for Tracker separately? Pushed some fixes earlier this evening to tracker, commits 82656fec to 5a0f5d2e. Also just filed bug #753262 to the rsvg gst plugin, so it's all clear here now I'd say.