long UI delay while feeds are updating

[rich-coe]

Investigate the causes of long UI hangs.

I notice a long delay (hang) while reading items while liferea is updating from the feedlists. I suspect that one or more feedlist may be holding a lock while a feedlist is updating items. The use of a feedlist script may be causing the issue because of the long time a script takes to run and the lock is being held while the script is running.

[rich-coe]

This is a pet peeve of my usage of liferea and I'm investigating how to fix it.

[nekohayo]

This is a duplicate of issue #113 or #36, and should probably be closed/merged into that... and patches would be very welcome indeed, this is one of my few annoyances as a fellow user!

[rich-coe]

I don't know if this is a recent symptom or a new one when I took an distribution update a couple of weeks ago.
I noticed that WebKitWebProcess, the one that's responsible for display content in the main tab, runs constantly. It starts with about 2-3% cpu and as time goes on, grows. I'm not using liferea at the time, and because I'm watching it, I see it running anywhere between 45% and 75% cpu. I wonder if displaying content on the main window, it accumulates background java script, like a giant Katamari Damacy ball, that wake up, run a bit, and sleep. It just grows and grows, until I reset it, and it starts off low again If anyone as any suggestions on how to view what's going on inside WebKitWebProcess?

[rich-coe]

I did a 30s trace of the running WebKitWebProcess, currently running at 43% CPU. There are 6980 lines of this triplet:

19800 recvmsg(3, {msg_namelen=0}, 0)    = -1 EAGAIN (Resource temporarily unavailable)
19800 recvmsg(3, {msg_namelen=0}, 0)    = -1 EAGAIN (Resource temporarily unavailable)
19800 poll([{fd=3, events=POLLIN}, {fd=4, events=POLLIN}, {fd=9, events=POLLIN}], 3, 0) = 0 (Timeout)

[nekohayo]

Hmm, here's a wild guess (I have no idea what I'm saying here) but isn't there some hidden option to enable the webkit webinspector in Liferea, which could let you pop up the standard web developer console, which I think would have some sort of memory monitor/profiler? Also test with Liferea set to disable javascript and plugins, if that changes anything?

[rich-coe]

Every time liferea loads an item, it calls webkit_web_view_load_bytes(). This causes webkit to load the new page. There's nothing to tell webkit to forget the previously loaded page. I going to try webkit_web_view_go_back() before loading a new page.

There doesn't seem to be any 'how to use' documentation for webkit, just the api page.

[rich-coe]

I've now looked at 50-100 items, and while at first with only looking at two items, WebKitWebProcess didn't accumulate any cpu time, it is now ticking away slowly at 10%.

[yaneti]

On a possibly related note Evolution which uses webkitgtk for the main mail view provokes the same -WebKitWebProces-keeps-increasingly-eating-cpu after some hours of use.

[rich-coe]

I found https://bugs.webkit.org/show_bug.cgi?id=165601 https://bugs.webkit.org/show_bug.cgi?id=179652 https://gitlab.gnome.org/GNOME/gnome-shell/-/issues/1875

The first one (resolved) addresses loading of dictionaries. The second (resolved) talks about an unimplemented ad-blocker for busy web pages. The last is under active development caused by the calendar causing many updates through dbus.

One interesting part of the comments in the last one, besides flame-graphs, is the use of sysprof, which statistically samples processes and has a nice graphical interface for drilling down on hot areas. I'll look into reproducing the problem with this tool to gather data.

gdk_frame_clock_get_refresh_info is getting called frequently, but cpu usage is only in 5% range at the moment.

[rich-coe]

Options to investigate

• slow down batch update that runs in the background so that it doesn't steal the UI focus
• find out what is locking the UI for long periods and fix that
• [undesirable] fetching the feed data separately

[rich-coe]

Notes from investigating this issue.

It's amazing how much you can identify when you move the database from ssd to spinning disk.

As identified in #113, itemset.c>itemset_merge_items() is a big culprit.

for every (new item)
    itemset_merge_item()
        itemset_generic_merge_check()
            O(N) look at every item in itemSet for (new item)
        db write(new item)
        db item duplicate check
        (!) download enclosures

One idea I had to speed up itemset_generic_merge_check() is compute a uniqueid from each existing item(id, title, description), and place the itemSet in fast lookup rbtree(). Then each lookup for a new item will be O(1). The cost of building the tree is O(N). The old cost is count(new items) O(N). And the new cost is O(N) + (count(new items) O(1))

Another issue I identified is this traceback:

#0  0x00007feb4163c66b in fdatasync () at /lib64/libc.so.6
#1  0x00007feb4757de22 in  () at /usr/lib64/libsqlite3.so.0
#2  0x00007feb4758ac88 in  () at /usr/lib64/libsqlite3.so.0
#3  0x00007feb4758b3d9 in  () at /usr/lib64/libsqlite3.so.0
#4  0x00007feb47661854 in  () at /usr/lib64/libsqlite3.so.0
#5  0x00007feb475a0562 in  () at /usr/lib64/libsqlite3.so.0
#6  0x00007feb475ad423 in  () at /usr/lib64/libsqlite3.so.0
#7  0x00007feb475a0e60 in sqlite3_step () at /usr/lib64/libsqlite3.so.0
#8  0x000000000042132e in db_subscription_metadata_update_cb
    (key=0xdd02350 "category", value=0x74ef690 "PLO", index=5997, user_data=0x4ba9640) at ../db.c:1490
#9  0x000000000042e252 in metadata_list_foreach
    (metadata=<optimized out>, func=func@entry=0x4212a0 <db_subscription_metadata_update_cb>, user_data=0x4ba9640) at ../metadata.c:267
#10 0x0000000000423ae1 in db_subscription_metadata_update (subscription=0x4ba9890, subscription=0x4ba9890)
    at ../db.c:1536
#11 0x0000000000423ae1 in db_subscription_update (subscription=subscription@entry=0x4ba9890) at ../db.c:1536
#12 0x0000000000433463 in subscription_process_update_result (result=0x73ebea0, user_data=0x4ba9890, flags=0)
    at ../subscription.c:237
#13 0x00000000004349fa in update_process_result_idle_cb (user_data=0xc4df380) at ../update.c:591
#14 0x00007feb418c5067 in  () at /usr/lib64/libglib-2.0.so.0
#15 0x00007feb418c92c7 in g_main_context_dispatch () at /usr/lib64/libglib-2.0.so.0
#16 0x00007feb418c9648 in  () at /usr/lib64/libglib-2.0.so.0
#17 0x00007feb418c96ff in g_main_context_iteration () at /usr/lib64/libglib-2.0.so.0
#18 0x00007feb41b00845 in g_application_run () at /usr/lib64/libgio-2.0.so.0
#19 0x000000000042dab4 in liferea_application_new (argc=3, argv=0x7fffa5935f88) at ../liferea_application.c:355
#20 0x00007feb4156bcca in __libc_start_main () at /lib64/libc.so.6
#21 0x000000000041e44a in _start () at ../sysdeps/x86_64/start.S:120