liferea tries to allocate 670Mb → abort (or oom evicted)

[DirkSchmitt]

Liferea seems to have some problems with memory allocation.

With sysctl -w vm.overcommit_memory=2 I liferea is dies with the following message:

Traceback (most recent call last): File "/usr/lib/x86_64-linux-gnu/liferea/plugins/gnome-keyring.py", line 37, in do_activate raise ValueError("Failed to unlock GnomeKeyring, error "+result) TypeError: Can't convert 'Result' object to str implicitly

(liferea:24974): GLib-ERROR **: ../../../../glib/gmem.c:100: failed to allocate 384767406 bytes Trace/Breakpoint ausgelöst

Allocation of 366 Megabyte seems also in current times a huge amount.

With sysctl -w vm.overcommit_memory=0

[< 0.000004>] lowmem_reserve[]: 0 0 4932 4932 4932 [< 0.000003>] Node 0 Normal free:42060kB min:42480kB low:53100kB high:63720kB active_anon:3497964kB inactive_anon:1268772kB active_file:328kB inactive_file:132kB unevictable:8848kB writepending:4kB present:5210112kB managed:5055632kB mlocked:8848kB kernel_stack:12704kB pagetables:53416kB bounce:0kB free_pcp:416kB local_pcp:164kB free_cma:0kB [< 0.000004>] lowmem_reserve[]: 0 0 0 0 0 [< 0.000002>] Node 0 DMA: 04kB 08kB 016kB 032kB 064kB 0128kB 0256kB 0512kB 11024kB (U) 12048kB (M) 34096kB (M) = 15360kB [< 0.000009>] Node 0 DMA32: 7504kB (UME) 9348kB (UE) 64816kB (UME) 24632kB (UE) 13564kB (UE) 40128kB (UME) 6256kB (UME) 1512kB (M) 11024kB (E) 02048kB 04096kB = 45544kB [< 0.000011>] Node 0 Normal: 12084kB (UME) 7208kB (UME) 48416kB (UME) 29732kB (UME) 13464kB (UE) 45128kB (UME) 0256kB 0512kB 01024kB 02048kB 0*4096kB = 42176kB [< 0.000010>] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB [< 0.000001>] 122846 total pagecache pages [< 0.000002>] 0 pages in swap cache [< 0.000001>] Swap cache stats: add 0, delete 0, find 0/0 [< 0.000000>] Free swap = 8089596kB [< 0.000001>] Total swap = 8089596kB [< 0.000001>] 2073179 pages RAM [< 0.000000>] 0 pages HighMem/MovableOnly [< 0.000001>] 55174 pages reserved [< 0.000000>] 0 pages cma reserved [< 0.000001>] 0 pages hwpoisoned [< 0.000001>] [ pid ] uid tgid total_vm rss nr_ptes nr_pmds swapents oom_score_adj name […] [< 0.000002>] [ 2933] 1100 2933 1637351 921402 2033 8 0 0 liferea [< 0.000002>] Out of memory: Kill process 2933 (liferea) score 228 or sacrifice child [< 0.000020>] Killed process 2933 (liferea) total-vm:6549404kB, anon-rss:3677496kB, file-rss:2724kB, shmem-rss:5388kB [< 0.246165>] oom_reaper: reaped process 2933 (liferea), now anon-rss:0kB, file-rss:0kB, shmem-rss:5388kB

Memory is enough on the machine (8 Gb RAM + 8 Gb Swap) Ofer 2 Gb RAM and the the whole swap space is unused.

env LC_ALL=C free -m

         total        used        free      shared  buff/cache   available

Mem: 7882 3707 2846 457 1329 3396 Swap: 7899 0 7899

Software version: 1.12.1-1~ubuntu16.04.1~c42.ppa1

[DirkSchmitt]

(liferea:19316): GLib-ERROR **: ../../../../glib/gmem.c:100: failed to allocate 703505504 bytes → 670 MB ??

[siebenmann]

I see Liferea allocating around 98 GB on startup on 64-bit Fedora 27 Linux; this is Liferea 1.12.2 with the default set of Liferea feeds. Its actual memory usage (measured via its RSS) is only a hundred MBytes and change. Much of the allocation appears to be real, in that pmap reports that there is, for example, a 64 GB anon region mapped 'rw---'.

[mozai]

Starting yesterday, Liferea v1.12.2 is allocating 112GB on start. doesn't use all of it, but it's still shocking. Turned out it was the "Media Player" plugin. This is how I fixed it: start liferea with liferea --disable-plugins. "Tools" menu, "Preferences", "Plugins" tab, clear the checkbox next to "Media Player". Quit liferea, restart as normal.

[lwindolf]

@mozai Thanks for this important hint on the media player!

[lwindolf]

Could you guys run Liferea with the GStreamer leak tracing enabled?

 GST_TRACERS="leaks" GST_DEBUG="GST_TRACER:7" liferea | grep GST_TRACER

I'd be interested if the GStreamer debugging detects leaks.

[mozai]

quit liferea. restarted with --disable-plugins, tools :: preferences :: plugins , turn on "media player" and all other plugins are off. close liferea. Started liferea with GST_TRACERS="leaks" GST_DEBUG="GST_TRACER:7" liferea | grep GST_TRACER

top says:

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                         
12241 moses     20   0  0.112t  98552  65216 S   0.0  1.2   0:04.74 liferea                                         
12252 moses     20   0 98.028g  65788  55712 S   0.0  0.8   0:00.21 WebKitWebProces                                 

the memory allocation is immediate, before liferea finishes the first run of fetching updates of RSS feeds. "resident" memory use is small, that "virt" of allocated memory is staggering, but maybe it won't be used. That "WebKitWebProcess" is weird because it only appears while liferea is running, but the parent pid (PPID) is '1', not liferea's '12241'. /usr/lib/x86_64-linux-gnu/webkit2gtk-4.0/WebKitWebProcess

First time I select a news article with embedded video, I see this in the terminal window:

0:00:00.020813941 12252 0x55bf658a8520 DEBUG             GST_TRACER gsttracer.c:164:gst_tracer_register:<registry0> update existing feature 0x55bf65b2a190 (latency)
0:00:00.020868154 12252 0x55bf658a8520 DEBUG             GST_TRACER gsttracer.c:164:gst_tracer_register:<registry0> update existing feature 0x55bf65b2a250 (log)
0:00:00.020883352 12252 0x55bf658a8520 DEBUG             GST_TRACER gsttracer.c:164:gst_tracer_register:<registry0> update existing feature 0x55bf65b2a310 (rusage)
0:00:00.020904721 12252 0x55bf658a8520 DEBUG             GST_TRACER gsttracer.c:164:gst_tracer_register:<registry0> update existing feature 0x55bf65b2a3d0 (stats)
0:00:00.020927868 12252 0x55bf658a8520 DEBUG             GST_TRACER gsttracer.c:164:gst_tracer_register:<registry0> update existing feature 0x55bf65b2a490 (leaks)
0:00:00.021007432 12252 0x55bf658a8520 TRACE             GST_TRACER gsttracerrecord.c:111:gst_tracer_record_build_format: object-alive.class, type-name=(structure)"value\,\ type\=\(type\)gchararray\,\ related-to\=\(GstTracerValueScope\)GST_TRACER_VALUE_SCOPE_PROCESS\;", address=(structure)"value\,\ type\=\(type\)gpointer\,\ related-to\=\(GstTracerValueScope\)GST_TRACER_VALUE_SCOPE_PROCESS\;", description=(structure)"value\,\ type\=\(type\)gchararray\,\ related-to\=\(GstTracerValueScope\)GST_TRACER_VALUE_SCOPE_PROCESS\;", ref-count=(structure)"value\,\ type\=\(type\)guint\,\ related-to\=\(GstTracerValueScope\)GST_TRACER_VALUE_SCOPE_PROCESS\;", trace=(structure)"value\,\ type\=\(type\)gchararray\,\ related-to\=\(GstTracerValueScope\)GST_TRACER_VALUE_SCOPE_PROCESS\;";
0:00:00.021036349 12252 0x55bf658a8520 DEBUG             GST_TRACER gsttracerrecord.c:125:gst_tracer_record_build_format: new format string: object-alive, type-name=(string)%s, address=(gpointer)%p, description=(string)%s, ref-count=(uint)%u, trace=(string)%s;
0:00:00.021070834 12252 0x55bf658a8520 TRACE             GST_TRACER gsttracerrecord.c:111:gst_tracer_record_build_format: object-refings.class, ts=(structure)"value\,\ type\=\(type\)guint64\,\ related-to\=\(GstTracerValueScope\)GST_TRACER_VALUE_SCOPE_PROCESS\;", type-name=(structure)"value\,\ type\=\(type\)gchararray\,\ related-to\=\(GstTracerValueScope\)GST_TRACER_VALUE_SCOPE_PROCESS\;", address=(structure)"value\,\ type\=\(type\)gpointer\,\ related-to\=\(GstTracerValueScope\)GST_TRACER_VALUE_SCOPE_PROCESS\;", description=(structure)"value\,\ type\=\(type\)gchararray\,\ related-to\=\(GstTracerValueScope\)GST_TRACER_VALUE_SCOPE_PROCESS\;", ref-count=(structure)"value\,\ type\=\(type\)guint\,\ related-to\=\(GstTracerValueScope\)GST_TRACER_VALUE_SCOPE_PROCESS\;", trace=(structure)"value\,\ type\=\(type\)gchararray\,\ related-to\=\(GstTracerValueScope\)GST_TRACER_VALUE_SCOPE_PROCESS\;";
0:00:00.021086226 12252 0x55bf658a8520 DEBUG             GST_TRACER gsttracerrecord.c:125:gst_tracer_record_build_format: new format string: object-refings, ts=(guint64)%lu, type-name=(string)%s, address=(gpointer)%p, description=(string)%s, ref-count=(uint)%u, trace=(string)%s;

Also, a "WebKitNetworkProcess" appears, also with staggering memory allocation but not much memory in use, and also owned by PPID 1. /usr/lib/x86_64-linux-gnu/webkit2gtk-4.0/WebKitNetworkProcess

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                         
12241 moses     20   0  0.112t 104048  70356 S   0.0  1.3   0:09.50 liferea                                         
12252 moses     20   0 98.543g 109228  76916 S   0.3  1.3   0:03.94 WebKitWebProces                                 
12254 moses     20   0 98.103g  43588  29784 S   0.0  0.5   0:00.30 WebKitNetworkPr                                 

There's what looks like a video player embed in the article view area, with a picture of the first frame of video, a play button, and a slider, and a timer. I can move the slider to no other effect. The play button does not react to clicking. Viewing another article that has a video embed does not produce more messages in the terminal.

[mozai]

After the above tests, I disabled Tools :: Preferences :: Plugins :: Media Player , quit liferea, started it again with --disable-plugins , but it's still allocating hundreds of gigabytes, and the video embeds are still appearing but not working, and GST_DEBUG is still uttering messages to stderr. So the workaround I described in June isn't working today. ... or maybe the Media Player plugin can't be disabled anymore?

[Leiaz]

@mozai The media player plugin is for media attached as enclosures to the feed, not videos embedded in the html. WebKitGtk renders those. Both use GStreamer.