search

fanglingsu / vimb

Vimb - the vim like browser is a webkit based web browser that behaves like the vimperator plugin for the firefox and usage paradigms from the great editor vim. The goal of vimb is to build a completely keyboard-driven, efficient and pleasurable browsing-experience.
https://fanglingsu.github.io/vimb/
GNU General Public License v3.0
1.34k stars 100 forks source link

Ctrl-Q is dependably faster than :quit #165

Closed sdothum closed 9 years ago

sdothum commented 9 years ago

What command is Ctrl-Q mapped to? I have noticed that :quit (and :quit!) are particularly laggy with one web page (tt-rss) while Ctrl-Q is not. Overall, I haven't noticed lag problems with :quit since I pruned my history down to a svelte 1K records so there must be something else going on with :quit and that particular web page.

fanglingsu commented 9 years ago

That's strange, in fact Ctrl-Q does the same like :quit. Do you have JavaScript enabled? Have you compiled vimb against GTK2 or GTK3? At the time I can't reproduce the issue, Ctrl-Q feels as fast as :quit.

sdothum commented 9 years ago

I haven't tried GTK3.

The problem only appears to exist with the tt-rss web page -- mapping :quit to a key or manually entering :quit doesn't make any difference. But what is weird is that Ctrl-Q closes that particular page instantly without problem. Even loaded with a default null config file, :quit lags significantly to Ctrl-Q with that one web page.

What I did discover is that the :quit action for that particular page will close the instant Esc or command mode (":") is entered, without which, the :quit will take several seconds on its own. So if I enter :quit, then immediately press Esc, the page will close instantly. Weird.. Does Ctrl-Q do anything after the :quit?

Not a big deal -- 1) I rarely close that page; 2) I can use Ctrl-Q when necessary (or just hit the Esc key if I issued :quit without Ctrl-Q). Why Ctrl-Q doesn't experience the same lag is a mystery.

semarie commented 9 years ago

@sdothum Does your window-manager have a mapping for Ctrl-Q (for closing window for example) ?

But the codepath should be the same (vb_quit is called on destroy signal too).

sdothum commented 9 years ago

semarie No assignment for Ctrl-Q in the wm (using herbstluftwm) -- I use Ctrl-W for closing the window, but that closes the tabbed+vimb app altogether.

fanglingsu commented 9 years ago

@sdothum Can you provide the full URL where the issue appears?

  1. Does the issue depend on tabbed? Can you check with and without running vimb in tabbed.
  2. Can you reproduce the issue also when there is only one vimb instance running? Maybe there is some file locking issue that slows down :quit
  3. Can you please rename the config directory to run vimb without any disturbing files.
  4. Does the issue appear always on this site or only after browsing some time?
  5. Can you try ::quit or : quit. This avoid the command to be written to command history. This should ensure that the lag isn't caused by file write operation.

As you can see, I've no glue what should be the difference between <C-Q> and :quit.

sdothum commented 9 years ago

tt-rss is an rss aggregator http://tt-rss.org/redmine/projects/tt-rss/wiki local to my machine which is configured on my system and hosted on the nginx web server at

http://localhost:8000/tt-rss

Well, I did discover the reason why Ctrl-Q is instantaneous: Ctrl-Q causes tabbed to close the tab! Without tabbed (i.e. running vimb as a single instance), Ctrl-Q takes as long as :quit. So that is good! Ctrl-Q == :quit.

With a single vimb instance, and clean .config/vimb directory (with only default files created by the running instance of vimb), tt-rss (tiny tiny rss) :quit lag remains. This is not dependent on usage -- just loading the page followed by an immediate :quit encounters a lag. No difference with the ::quit and : quit so history processing is not an issue.

The previously reported property holds: issuing :quit on that web page and hitting Esc or ":" immediately afterwards, closes the web page instantly. It's the only web page that seems to have this lag! I tried it on qutebrowser just to be sure this isn't the 1st time I've noticed this, and it closes the page immediately without any lag on a :quit command. Ditto luakit.

It's a mystery..

fanglingsu commented 9 years ago

This keeps strange, in my opinion the closing of tabbed tab should do the same like <C-Q> and :quit. But we're a little closer to the issue. I can't reproduce the issue here, vimb quits immediately independent from the opened page. If you open the tt-rss page and go to another none affected page and quit, is this still slow?

sdothum commented 9 years ago

The laggy :quit appears to be tied to whatever is unique about the tt-rss page. Opening another non-tt-rss web page (even a rss article link off that page) closes immediately on :quit.

fanglingsu commented 9 years ago

I'll do a new branch of vimb in the next days with some debugging functions to track the times for various operations done on quit. Hope this will help to get this solved for you.

sdothum commented 9 years ago

I'll keep an eye out for the branch! Thanks!

fanglingsu commented 9 years ago

OK, the branch is done. Can you please check the issue-165 branch. Following line should be the fastest way to get the times, but you can also call quit by hand. And in case the autocommand's quit is faster you even should do it by hand.

src/vimb -C 'au LoadFinished * quit' http://tt-rss.org/redmine/projects/tt-rss/wiki
sdothum commented 9 years ago

I am getting a compile error with the issue-165 patch on make..

cc hints.o
hints.c: In function ‘hints_init’:
hints.c:65:49: error: ‘HINTS_JS’ undeclared (first use in this function)
         hints.obj = js_create_object(hints.ctx, HINTS_JS);
                                                 ^
hints.c:65:49: note: each undeclared identifier is reported only once for each function it appears in
Makefile:38: recipe for target 'hints.o' failed
make[1]: *** [hints.o] Error 1
Makefile:42: recipe for target 'vimb' failed
make: *** [vimb] Error 2

Am I missing a library?

fanglingsu commented 9 years ago

Am I missing a library?

No, the HINTS_JS is generated on make out of the hinting.js file via js2h.sh script. Maybe this failed. But I have not changed anything that could cause this error I think. Have you tried to run make clean first?

sdothum commented 9 years ago

There was an arch permissions problem from the directory I was trying the build from. Compiled ok once moved the patched sources to home dir. Output of your test url and my local tt-rss aggregator:

Wed 3:19 48pm ~/vimb-issue-165 ❯❯❯ src/vimb -C 'au LoadFinished * quit' http://tt-rss.org/redmine/projects/tt-rss/wiki
java version "1.7.0_75"
OpenJDK Runtime Environment (IcedTea 2.5.4) (Arch Linux build 7.u75_2.5.4-1-x86_64)
OpenJDK 64-Bit Server VM (build 24.75-b04, mixed mode)

DEBUG: arh.c:114:arh_free() timer: elapsed: 0.000001s
DEBUG: arh.c:123:arh_run()  uri: http://tt-rss.org/redmine/projects/tt-rss/wiki
DEBUG: arh.c:123:arh_run()  uri: http://tt-rss.org/redmine/stylesheets/jquery/jquery-ui-1.9.2.css?1385196105
DEBUG: arh.c:123:arh_run()  uri: http://tt-rss.org/redmine/stylesheets/application.css?1385196105
DEBUG: arh.c:123:arh_run()  uri: http://tt-rss.org/redmine/javascripts/jquery-1.8.3-ui-1.9.2-ujs-2.0.3.js?1385196105
DEBUG: arh.c:123:arh_run()  uri: http://tt-rss.org/redmine/javascripts/application.js?1385196105
DEBUG: arh.c:123:arh_run()  uri: http://tt-rss.org/images/btn_donate_SM.gif
DEBUG: arh.c:123:arh_run()  uri: http://tt-rss.org/images/flattr-badge-large.png
DEBUG: arh.c:123:arh_run()  uri: http://tt-rss.org/redmine/images/external.png
DEBUG: arh.c:123:arh_run()  uri: http://tt-rss.org/redmine/favicon.ico?1288882477
DEBUG: main.c:456:vb_quit() timer: elapsed: 0.000123s
DEBUG: main.c:465:vb_quit() timer: elapsed: 0.000143s
DEBUG: main.c:470:vb_quit() timer: elapsed: 0.000004s
DEBUG: ex.c:919:ex_quit()   timer: elapsed: 0.000303s
DEBUG: completion.c:197:completion_clean()  timer: elapsed: 0.000000s
DEBUG: map.c:126:map_cleanup()  timer: elapsed: 0.000005s
DEBUG: mode.c:44:mode_cleanup() timer: elapsed: 0.000002s
DEBUG: setting.c:344:setting_cleanup()  timer: elapsed: 0.000017s
DEBUG: history.c:71:history_cleanup()   timer: elapsed: 0.001529s
DEBUG: main.c:1119:session_cleanup()    timer: elapsed: 0.005756s
DEBUG: main.c:1170:register_cleanup()   timer: elapsed: 0.000000s
DEBUG: autocmd.c:82:autocmd_cleanup()   timer: elapsed: 0.000001s
DEBUG: arh.c:114:arh_free() timer: elapsed: 0.000000s
DEBUG: io.c:100:io_cleanup()    timer: elapsed: 0.000000s
DEBUG: main.c:1583:vb_cleanup() timer: elapsed: 0.000001s
DEBUG: main.c:1591:vb_cleanup() timer: elapsed: 0.000000s
DEBUG: main.c:1688:main()   timer: elapsed: 0.007395s%

Wed 3:20 27pm ~/vimb-issue-165 ❯❯❯ src/vimb -C 'au LoadFinished * quit' http://localhost:8000/tt-rss
java version "1.7.0_75"
OpenJDK Runtime Environment (IcedTea 2.5.4) (Arch Linux build 7.u75_2.5.4-1-x86_64)
OpenJDK 64-Bit Server VM (build 24.75-b04, mixed mode)

DEBUG: arh.c:114:arh_free() timer: elapsed: 0.000001s
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/dijit/themes/claro/claro.css?1418236398
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/css/layout.css?1418236398
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/themes/default.css?1421588381
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/prototype.js?1418236398
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/scriptaculous/scriptaculous.js?1418236398&load=effects,controls
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/dojo/dojo.js?1418236398
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/dojo/tt-rss-layer.js?1418236398
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/errors.php?1418236398&mode=js
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/themes/particle_fork.css
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/themes/particle_base.css
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/scriptaculous/effects.js
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/scriptaculous/controls.js
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/dojo/selector/acme.js
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/dojo/nls/tt-rss-layer_en-us.js
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/images/indicator_tiny.gif
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/images/error.png
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/images/new_version.png
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/themes/particle_images/noise.png
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/dojo/resources/blank.gif
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/images/favicon.png
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/dijit/form/ComboBox.js** Message: console message: http://localhost:8000/tt-rss/ @170: setCookie: ttrss_test => TEST: false

DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/backend.php
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/dijit/themes/a11y/indeterminate_progress.gif
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/themes/particle_images/angle-down.png** Message: console message: http://localhost:8000/tt-rss/ @151: EXCEPTION: Exception: SyntaxError: JSON Parse error: Unexpected EOF
Function: backend_sanity_check_callback()

DEBUG: main.c:456:vb_quit() timer: elapsed: 0.009189s
DEBUG: main.c:465:vb_quit() timer: elapsed: 0.000130s
DEBUG: main.c:470:vb_quit() timer: elapsed: 0.000004s
DEBUG: ex.c:919:ex_quit()   timer: elapsed: 0.009350s
DEBUG: completion.c:197:completion_clean()  timer: elapsed: 0.000000s
DEBUG: map.c:126:map_cleanup()  timer: elapsed: 0.000003s
DEBUG: mode.c:44:mode_cleanup() timer: elapsed: 0.000001s
DEBUG: setting.c:344:setting_cleanup()  timer: elapsed: 0.000012s
DEBUG: history.c:71:history_cleanup()   timer: elapsed: 0.000993s[1]    27957 segmentation fault (core dumped)  src/vimb -C 'au LoadFinished * quit' http://localhost:8000/tt-rss
fanglingsu commented 9 years ago

According to the measured times the quit should be fast (a little bit more than the 0.009350s for ex_quit). But in case of you local page, there is an segfault. I can imagine that this could take some time if there is a core dump written.

Is quit also slow on http://tt-rss.org/redmine/projects/tt-rss/wiki or only on your local tt-rss page?

sdothum commented 9 years ago

The tt-rss project page closes instantly.. but it is just a static web page. The local page is one generated by the tt-rss app itself (similar to the old google reader -- an aggregated page of rss feeds updated as per configured refresh setting). I wonder if the seg fault exists for the other browsers on :quit but their tabs just close faster -- though it seems tied to vimb's history cleanup for some reason?

Certainly if this is the only corner case reported causing problems for vimb.. Ctrl-Q via tabbed is the convenient solution -- I presume closing the tab via tabbed bypasses vimb history processing?

fanglingsu commented 9 years ago

The closing of vimb by CTRL-Q via tabbed does definitely process the history and all the other things.

sdothum commented 9 years ago

I don't suppose this should cause any problems, as closing that page is always the same url, so I don't need it in history (I open it from bookmarks). And I generally leave that page open all the time!

fanglingsu commented 9 years ago

You are right, it doesn't matter, like @semarie already mentioned the executed code is in all cases the same :quit, <C-Q>, closing of tabbed tab via <C-Q> or closing the window via window manager.

We should fix the segfault or first get the backtrace to see what's the reason for this.

sdothum commented 9 years ago

Where do we go from here then? Any more tests you need from me?

fanglingsu commented 9 years ago

A back trace of the coredump would be required.

sdothum commented 9 years ago

Trapped this window that flashed during the segfault

http://imgur.com/bTEQvAh

Coredump produced:(gdb) run -C 'au LoadFinished * quit' http://localhost:8000/tt-rss
Starting program: /home/shum/vimb-issue-165/src/vimb -C 'au LoadFinished * quit' http://localhost:8000/tt-rss
warning: Could not load shared library symbols for linux-vdso.so.1.
Do you need "set solib-search-path" or "set sysroot"?
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/usr/lib/libthread_db.so.1".
[New Thread 0x7fffe5d9d700 (LWP 29997)]
[New Thread 0x7fffa5498700 (LWP 29998)]
[New Thread 0x7fff9f90f700 (LWP 30004)]
[New Thread 0x7fff9f10e700 (LWP 30005)]
[New Thread 0x7fff9e90d700 (LWP 30006)]
[New Thread 0x7fff9dcfa700 (LWP 30019)]
java version "1.7.0_75"
OpenJDK Runtime Environment (IcedTea 2.5.4) (Arch Linux build 7.u75_2.5.4-1-x86_64)
OpenJDK 64-Bit Server VM (build 24.75-b04, mixed mode)
[New Thread 0x7fff9ca78700 (LWP 30026)]

DEBUG: arh.c:114:arh_free() timer: elapsed: 0.000001s[New Thread 0x7fff9718f700 (LWP 30028)]
[New Thread 0x7fff9698e700 (LWP 30029)]
[New Thread 0x7fff9618d700 (LWP 30030)]
[New Thread 0x7fff9598c700 (LWP 30031)]
[New Thread 0x7fff9518b700 (LWP 30032)]
[New Thread 0x7fff9498a700 (LWP 30033)]
[New Thread 0x7fff7bfff700 (LWP 30034)]

DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss[New Thread 0x7fff7b3fe700 (LWP 30035)]

DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/dijit/themes/claro/claro.css?1418236398
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/css/layout.css?1418236398
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/themes/default.css?1421588381[New Thread 0x7fff7abfd700 (LWP 30037)]

DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/prototype.js?1418236398
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/scriptaculous/scriptaculous.js?1418236398&load=effects,controls
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/dojo/dojo.js?1418236398
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/dojo/tt-rss-layer.js?1418236398
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/errors.php?1418236398&mode=js[New Thread 0x7fff7a3fc700 (LWP 30038)]

DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/themes/particle_fork.css
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/themes/particle_base.css
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/scriptaculous/effects.js
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/scriptaculous/controls.js
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/dojo/selector/acme.js
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/dojo/nls/tt-rss-layer_en-us.js
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/images/indicator_tiny.gif
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/images/error.png
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/images/new_version.png
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/themes/particle_images/noise.png
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/dojo/resources/blank.gif
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/images/favicon.png
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/dijit/form/ComboBox.js** Message: console message: http://localhost:8000/tt-rss/ @170: setCookie: ttrss_test => TEST: false

DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/backend.php
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/lib/dijit/themes/a11y/indeterminate_progress.gif
DEBUG: arh.c:123:arh_run()  uri: http://localhost:8000/tt-rss/themes/particle_images/angle-down.png** Message: console message: http://localhost:8000/tt-rss/ @151: EXCEPTION: Exception: SyntaxError: JSON Parse error: Unexpected EOF
Function: backend_sanity_check_callback()

DEBUG: main.c:456:vb_quit() timer: elapsed: 0.010450s
DEBUG: main.c:465:vb_quit() timer: elapsed: 0.000127s
DEBUG: main.c:470:vb_quit() timer: elapsed: 0.000004s
DEBUG: ex.c:919:ex_quit()   timer: elapsed: 0.010613s
DEBUG: completion.c:197:completion_clean()  timer: elapsed: 0.000001s
DEBUG: map.c:126:map_cleanup()  timer: elapsed: 0.000004s
DEBUG: mode.c:44:mode_cleanup() timer: elapsed: 0.000002s
DEBUG: setting.c:344:setting_cleanup()  timer: elapsed: 0.000020s
DEBUG: history.c:71:history_cleanup()   timer: elapsed: 0.001104s
Program received signal SIGSEGV, Segmentation fault.
0x0000000000411639 in editable_focus_cb ()
(gdb) where
#0  0x0000000000411639 in editable_focus_cb ()
#1  0x00007fffeb7661f0 in ffi_call_unix64 () from /usr/lib/libffi.so.6
#2  0x00007fffeb765c58 in ffi_call () from /usr/lib/libffi.so.6
#3  0x00007ffff37bfa74 in g_cclosure_marshal_generic () from /usr/lib/libgobject-2.0.so.0
#4  0x00007ffff37bf255 in g_closure_invoke () from /usr/lib/libgobject-2.0.so.0
#5  0x00007ffff7002e00 in ?? () from /usr/lib/libwebkitgtk-1.0.so.0
#6  0x00007ffff63e5c9f in ?? () from /usr/lib/libwebkitgtk-1.0.so.0
#7  0x00007ffff63e6139 in ?? () from /usr/lib/libwebkitgtk-1.0.so.0
#8  0x00007ffff63df578 in ?? () from /usr/lib/libwebkitgtk-1.0.so.0
#9  0x00007ffff63e10fe in ?? () from /usr/lib/libwebkitgtk-1.0.so.0
#10 0x00007ffff63dc1c2 in ?? () from /usr/lib/libwebkitgtk-1.0.so.0
#11 0x00007ffff65b62b4 in ?? () from /usr/lib/libwebkitgtk-1.0.so.0
#12 0x00007ffff63acd19 in ?? () from /usr/lib/libwebkitgtk-1.0.so.0
#13 0x00007ffff67ede6d in ?? () from /usr/lib/libwebkitgtk-1.0.so.0
#14 0x00007ffff63d5fc1 in ?? () from /usr/lib/libwebkitgtk-1.0.so.0
#15 0x00007ffff6c68a8e in ?? () from /usr/lib/libwebkitgtk-1.0.so.0
#16 0x00007fffa549a0e5 in ?? ()
#17 0x00007fff7b7fec38 in ?? ()
#18 0x00007ffff326700f in ?? () from /usr/lib/libjavascriptcoregtk-1.0.so.0
#19 0x0000000000000000 in ?? ()
(gdb) q

Hope this helps.

fanglingsu commented 9 years ago

This could be the same as #157.

sdothum commented 9 years ago

Dunno.. though it does beg the question why other webkit browsers like luakit don't seem to have a problem :quit'ing that page (unless the segfault is there but the close tab mechanism masks the problem)

It's not a deal breaker for me. My transition from luakit which I've pimped extensively over the years to vimb was so effortless and seamless that vimb is my goto browser for now. Being a vim fanatic helps :-)

fanglingsu commented 9 years ago

I like to see the issue fixed, because it's possible that other user are also affected by the segfault. The history ist cleaned properly, because the timer data are written to stdout. This means the segfault appears after that, and after history cleanup the session is cleaned (removing of HSTS session provider and dumping of soup cache).

Can you please test again the master branch with you local tt-rss if the segfault appear there too? If it appears you should try to compile without FEATURE_HSTS and check for the segfault. If this still occurs, compile vimb without FEATURE_SOUP_CACHE. If both feature are disabled, there is nothing to do in session_cleanup(). If the segfault is gone by this, we have to check the logic in session_cleanup().

sdothum commented 9 years ago

Test with master branch (using AUR vimb-git) produced same segfault with popup window.

Test without FEATURE_HSTS compiled yielded segfault BUT the tt-rss related popup window did not appear.

(gdb) run -C 'au LoadFinished * quit' http://localhost:8000/tt-rss
Starting program: /home/shum/vimb/src/vimb -C 'au LoadFinished * quit' http://localhost:8000/tt-rss
warning: Could not load shared library symbols for linux-vdso.so.1.
Do you need "set solib-search-path" or "set sysroot"?
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/usr/lib/libthread_db.so.1".

Program received signal SIGSEGV, Segmentation fault.
0x0000000000410709 in mode_input_changed ()
(gdb) q

Test without FEATURE_HSTS and FEATURE_SOUP_CACHE also segfaulted without popup window

(gdb) run -C 'au LoadFinished * quit' http://localhost:8000/tt-rss
Starting program: /home/shum/vimb/src/vimb -C 'au LoadFinished * quit' http://localhost:8000/tt-rss
warning: Could not load shared library symbols for linux-vdso.so.1.
Do you need "set solib-search-path" or "set sysroot"?
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/usr/lib/libthread_db.so.1".

Program received signal SIGSEGV, Segmentation fault.
0x0000000000410709 in mode_input_changed ()
(gdb)

Hope this helps..

fanglingsu commented 9 years ago

Hm, the segfault appears now on another position. It would be great if we can find a public accesible page where this issue appears too.

Does the issue appear with disabled JavaScript? Or when you run :quit by hand a little later than the autocmd would do?

sdothum commented 9 years ago

.. hold on. I just tried running the last recompiled version without the autocmd and the segfault occurred. (will test again with hsts off, then with soup cache off)..

sdothum commented 9 years ago

OK. Test 1 with HSTS off.. segfault with popup window previously noted..

(gdb) run -C 'au LoadFinished * quit' http://localhost:8000/tt-rss
Starting program: /usr/bin/vimb -C 'au LoadFinished * quit' http://localhost:8000/tt-rss
warning: Could not load shared library symbols for linux-vdso.so.1.
Do you need "set solib-search-path" or "set sysroot"?
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/usr/lib/libthread_db.so.1".
** Message: console message: http://localhost:8000/tt-rss/ @170: setCookie: ttrss_test => TEST: false

** Message: console message: http://localhost:8000/tt-rss/ @151: EXCEPTION: Exception: SyntaxError: JSON Parse error: Unexpected EOF
Function: backend_sanity_check_callback()

Program received signal SIGSEGV, Segmentation fault.
0x0000000000411d87 in ?? ()
(gdb) q
sdothum commented 9 years ago

Test 2 with HSTS off and Soup Cache off.. segfault with popup window previously noted..

(gdb) run -C 'au LoadFinished * quit' http://localhost:8000/tt-rss
Starting program: /usr/bin/vimb -C 'au LoadFinished * quit' http://localhost:8000/tt-rss
warning: Could not load shared library symbols for linux-vdso.so.1.
Do you need "set solib-search-path" or "set sysroot"?
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/usr/lib/libthread_db.so.1".
** Message: console message: http://localhost:8000/tt-rss/ @170: setCookie: ttrss_test => TEST: false

** Message: console message: http://localhost:8000/tt-rss/ @151: EXCEPTION: Exception: SyntaxError: JSON Parse error: Unexpected EOF
Function: backend_sanity_check_callback()

Program received signal SIGSEGV, Segmentation fault.
0x0000000000411d87 in ?? ()
(gdb) q

Hope this helps better!

fanglingsu commented 9 years ago

0x0000000000411d87 in ?? () you should compile with debug symbols to see where the segfault appeared.

  1. Try again but without the autocmd, type :quit into inputbox.
  2. Like 1. but start vimb with disabled JavaScript vimb -C 'set scripts=off'.
sdothum commented 9 years ago

Test 1. Manual quit entered at point just preceding the libsoup-warning at bottom of gdb output. :quit did not produce a segfault but the pause was there, then the libsoup-warning and remaining messages were output.

(gdb) run
Starting program: /usr/bin/vimb 
warning: Could not load shared library symbols for linux-vdso.so.1.
Do you need "set solib-search-path" or "set sysroot"?
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/usr/lib/libthread_db.so.1".

(vimb:31616): GLib-GObject-CRITICAL **: g_closure_unref: assertion 'closure->ref_count > 0' failed
[New Thread 0x7fff79bbf700 (LWP 32149)]
** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @170: setCookie: ttrss_test => TEST: false

[New Thread 0x7fff631a8700 (LWP 32152)]
** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: sanity check ok

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: reading init-params...

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: on_catchup_show_next_feed => 0

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: hide_read_feeds => 0

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: enable_feed_cats => 1

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: feeds_sort_by_unread => 0

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: confirm_feed_catchup => 0

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: cdm_auto_catchup => 1

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: fresh_article_max_age => 24

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: hide_read_shows_special => 1

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: combined_display_mode => 1

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: icons_url => "feed-icons"

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: cookie_lifetime => 86400

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: default_view_mode => "adaptive"

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: default_view_limit => 30

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: default_view_order_by => "feed_dates"

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: bw_limit => 0

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: label_base_index => -1024

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: theme => "default.css"

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: plugins => "Auth_Internal, Note, Updater, Af_NatGeo, Af_RedditImgur, Af_SciAm, Close_Button, Embed_Original, Mark_Button, Shorten_Expanded"

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: php_platform => "Linux"

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: php_version => "5.6.5"

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: sanity_checksum => "e667f30199dfb16647b718705efc0294f76dc365"

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: max_feed_id => 358

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: num_feeds => 354

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: hotkeys => [["c","a","f","g"],{"k":"next_feed","j":"prev_feed","n":"next_article","p":"prev_article","(38)|up":"prev_article","(40)|down":"next_article","(191)|/":"search_dialog","s":"toggle_mark","*s":"toggle_publ","u":"toggle_unread","*t":"edit_tags","*d":"dismiss_selected","*x":"dismiss_read","o":"open_in_new_window","c p":"catchup_below","c n":"catchup_above","*n":"article_scroll_down","*p":"article_scroll_up","*(38)|Shift+up":"article_scroll_up","*(40)|Shift+down":"article_scroll_down","a *w":"toggle_widescreen","a e":"toggle_embed_original","e":"email_article","a q":"close_article","a a":"select_all","a u":"select_unread","a *u":"select_marked","a p":"select_published","a i":"select_invert","a n":"select_none","f r":"feed_refresh","f a":"feed_unhide_read","f s":"feed_subscribe","f e":"feed_edit","f q":"feed_catchup","f x":"feed_reverse","f *d":"feed_debug_update","f *c":"toggle_combined_mode","f c":"toggle_cdm_expanded","*q":"catchup_all","x":"cat_toggle_collapse","g a":"goto_all","g f":"goto_fresh","g s":"goto_marked","g p":"goto_published","g t":"goto_tagcloud","g *p":"goto_prefs","(9)|Tab":"select_article_cursor","c l":"create_label","c f":"create_filter","c s":"collapse_sidebar","^(191)|Ctrl+/":"help_dialog","^(38)|Ctrl-up":"prev_article_noscroll","^(40)|Ctrl-down":"next_article_noscroll"}]

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: csrf_token => "87737727654ddeef40ffaf4.83621216"

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: widescreen => 0

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @284: IP: simple_update => false

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @638: PluginHost::run 8

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @638: PluginHost::run 4

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @86: second stage ok

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @61: viewCurrentFeed

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @638: PluginHost::run 3

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @351: ?op=feeds&method=view&feed=-3&view_mode=adaptive&order_by=feed_dates&m=ForceUpdate&cat=false

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @638: PluginHost::run 4

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @638: PluginHost::run 9

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @392: headlines_callback2 [offset=0] B:false I:false

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @404: no cached articles received

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @355: scheduling request of counters...

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @356: ?op=rpc&method=getAllCounters&seq=1

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @638: PluginHost::run 5

[New Thread 0x7fff620cf700 (LWP 32215)]
[New Thread 0x7fff618ce700 (LWP 32217)]
[New Thread 0x7fff60ecd700 (LWP 32219)]
** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @638: PluginHost::run 9

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @353: in feedlist init

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @231: about to remove splash, OMG!

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @231: removed splash!

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @638: PluginHost::run 3

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @351: ?op=feeds&method=view&feed=-3&view_mode=adaptive&order_by=feed_dates&m=ForceUpdate&cat=false

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @638: PluginHost::run 4

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @355: scheduling request of counters...

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @356: ?op=rpc&method=getAllCounters&seq=2

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @356: request_counters: rate limit reached: 0

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @638: PluginHost::run 9

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @392: headlines_callback2 [offset=0] B:false I:false

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @404: no cached articles received

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @355: scheduling request of counters...

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @356: ?op=rpc&method=getAllCounters&seq=3

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @638: PluginHost::run 5

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @123: [handle_rpc_json] sequence mismatch: 2 (want: 3)

** Message: console message: http://localhost:8000/tt-rss/#f=-3&c=0 @638: PluginHost::run 9

[Thread 0x7fff631a8700 (LWP 32152) exited]
[Thread 0x7fff7a9f7700 (LWP 32148) exited]
[Thread 0x7fff7b3fe700 (LWP 31730) exited]
[Thread 0x7fff79bbf700 (LWP 32149) exited]
[Thread 0x7fff620cf700 (LWP 32215) exited]
[Thread 0x7fff618ce700 (LWP 32217) exited]
[New Thread 0x7fff618ce700 (LWP 32295)]
[New Thread 0x7fff620cf700 (LWP 32296)]
[New Thread 0x7fff79bbf700 (LWP 32297)]
[New Thread 0x7fff7a9f7700 (LWP 32298)]
[New Thread 0x7fff7b3fe700 (LWP 32299)]
[Thread 0x7fff620cf700 (LWP 32296) exited]
[Thread 0x7fff60ecd700 (LWP 32219) exited]
[Thread 0x7fff7b3fe700 (LWP 32299) exited]
[Thread 0x7fff618ce700 (LWP 32295) exited]
[Thread 0x7fff7a9f7700 (LWP 32298) exited]
[Thread 0x7fff79bbf700 (LWP 32297) exited]

(vimb:31616): libsoup-WARNING **: Cache flush finished despite 3 pending requests
[Thread 0x7fffa5498700 (LWP 31627) exited]
[Thread 0x7fff7bfff700 (LWP 31703) exited]
[Thread 0x7fff9498a700 (LWP 31698) exited]
[Thread 0x7fff9518b700 (LWP 31695) exited]
[Thread 0x7fff9598c700 (LWP 31693) exited]
[Thread 0x7fff9618d700 (LWP 31691) exited]
[Thread 0x7fff9698e700 (LWP 31690) exited]
[Thread 0x7fff9718f700 (LWP 31689) exited]
[Thread 0x7fff9ca78700 (LWP 31654) exited]
[Thread 0x7fff9dcfa700 (LWP 31647) exited]
[Thread 0x7fff9e90d700 (LWP 31632) exited]
[Thread 0x7fff9f10e700 (LWP 31631) exited]
[Thread 0x7fff9f90f700 (LWP 31630) exited]
[Thread 0x7ffff7fa1940 (LWP 31616) exited]
[Inferior 1 (process 31616) exited normally]
(gdb)

I reran the test with the recompiled (-g) vimb using the autocmd and it did segfault but with no debug symbols. So this may be a segfault in tt-rss by the way the page is being closed (Javascript related)? The delay is perhaps happening there?

Test 2 will not work because Javascript needs to be enabled for the tt-rss page to load.

While surfing around last night with vimb I thought I ran into a similar :quit page latency on some public sites but everytime I went back I couldn't reproduce it.. (I should have taken note of the urls at least.. will do so going forward)

fanglingsu commented 9 years ago

Another attept, can you disable FEATURE_SOUP_CACHE and check if the quit is faster (no need for a core dump)? Maybe the libsoup waits for pending request to be finished to flush the cache (even if the webview loading is stopped before the cleanup actions).

sdothum commented 9 years ago

Compiled with both hsts and soup_cache disabled: lag time (10s) to close window is still there compared to instantaneous for :quit'ing other web pages.

sdothum commented 9 years ago

OK.. something interesting. If I :open the tt-rss page, then :open a random web site (over the tt-rss page i.e. it is no longer present), :quit'ing the new site page also has the :quit delay reported!

Have no clue where you should look for this weird behaviour.. I doubt it is webkit as other webkit browsers don't display this behaviour (delay). A Javascript problem created by tt-rss that persists once that url is opened even after it is closed?..

fanglingsu commented 9 years ago

Meanwhile I tend to think that the issue is caused by JavaScript. So you can open the evil page, start the webinspector (normal mode command gF) and use this to check what's going on there. I don't know which tool would be best, but for the first you can try the timeline, click the record button and reload the page and look at the JavaScript events. Or you could check for excessive use of local- or session storage.

sdothum commented 9 years ago

Did a reload with the timelines enabled. A series of Javascripts are invoked. With record on, a regular interval of timer (?) activities mark the timeline after the page is loaded, nothing else. On :quit nothing else shows up (other than the timers) the timeline does not indicate any other activity -- just a pregnant pause, then the tab closes. Curious. Not sure where else to look.. Curious.

fanglingsu commented 9 years ago

If the migration to webkit2gtk would not be as hard as it is, I'd suggest to wait for this in hope that the issues will not appear there.

sdothum commented 9 years ago

Not a problem! It is more an anomaly for me than annoyance! -- I simply expedite the tab closure by pressing Esc for this particular instance.

Will be ready to test when your migration is completed.

fanglingsu commented 9 years ago

Closed out of long time of inactivity.