Quickly open PDF in new tab & close freezes tab

[rhuitl]

I'm afraid but there's another race (Chromium)... :(
When I open a PDF which opens in a new tab and immediately close the tab (while it's still loading) with okularplugin using Ctrl+W, the first tab freezes (you may have to try this a couple of times). This does not happen if there's at least one more okularplugin tab open, so it's probably related to the cleanup that's done when the last plugin container gets destroyed.

[afrimberger]

You should definitely work as a software tester ;-). You're doing a good job.

The bug you mentioned is related to a unlucky resource clean up order. I will push the commit with the fix in a few minutes.

[rhuitl]

Haha thanks :-) I will keep reporting any issues I can provoke...
Btw, this bug isn't fixed, still freezes the parent tab. When it freezes, the plugin is stuck somewhere in libokularcore with

PartWin::~PartWin()
  delete m_part

on the call stack.

[afrimberger]

Since changing the resource clean up order I can't reproduce this bug anymore. Can you please install the debugging symbols for okular (usually packagename-dbg in Debian flavoured systems) and provide a full backtrace when this bug happens again?

[rhuitl]

Here's the backtrace:

and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
For bug reporting instructions, please see:
<http://bugs.launchpad.net/gdb-linaro/>...
Reading symbols from /usr/lib/chromium-browser/chromium-browser...(no debugging symbols found)...done.
(gdb) r
Starting program: /usr/lib/chromium-browser/chromium-browser --type=plugin --plugin-path=/home/robert/devel/okularplugin/build/lib/libokularplugin.so --lang=de --channel=28497.21.2053922393
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[New Thread 0x7fffed253700 (LWP 28768)]
KGlobal::locale::Warning your global KLocale is being recreated with a valid main component instead of a fake component, this usually means you tried to call i18n related functions before your main component t since it most likely will not work
tcmalloc: large alloc 1073745920 bytes == 0x55555a2d8000 @
[New Thread 0x7fffda45b700 (LWP 28769)]
[New Thread 0x7fffd9c5a700 (LWP 28770)]
[New Thread 0x7fffd882b700 (LWP 28771)]
[Thread 0x7fffda45b700 (LWP 28769) exited]
[New Thread 0x7fffda45b700 (LWP 28772)]
[Thread 0x7fffd9c5a700 (LWP 28770) exited]
[Thread 0x7fffda45b700 (LWP 28772) exited]
[New Thread 0x7fffda45b700 (LWP 28773)]
[Thread 0x7fffda45b700 (LWP 28773) exited]
[New Thread 0x7fffda45b700 (LWP 28774)]
[New Thread 0x7fffd9c5a700 (LWP 28775)]
[Thread 0x7fffda45b700 (LWP 28774) exited]
[Thread 0x7fffd9c5a700 (LWP 28775) exited]
[New Thread 0x7fffd9c5a700 (LWP 28776)]
[New Thread 0x7fffda45b700 (LWP 28777)]
[New Thread 0x7fffd3cd3700 (LWP 28778)]
[Thread 0x7fffda45b700 (LWP 28777) exited]
[Thread 0x7fffd3cd3700 (LWP 28778) exited]
[New Thread 0x7fffd3cd3700 (LWP 28779)]
[Thread 0x7fffd3cd3700 (LWP 28779) exited]
[New Thread 0x7fffd3cd3700 (LWP 28780)]
[New Thread 0x7fffda45b700 (LWP 28781)]
[Thread 0x7fffd3cd3700 (LWP 28780) exited]
[New Thread 0x7fffd3cd3700 (LWP 28782)]
[Thread 0x7fffda45b700 (LWP 28781) exited]
[Thread 0x7fffd3cd3700 (LWP 28782) exited]
[New Thread 0x7fffd3cd3700 (LWP 28783)]
[Thread 0x7fffd3cd3700 (LWP 28783) exited]
[New Thread 0x7fffd3cd3700 (LWP 28784)]
[New Thread 0x7fffda45b700 (LWP 28785)]
[Thread 0x7fffd3cd3700 (LWP 28784) exited]
[New Thread 0x7fffd3cd3700 (LWP 28786)]
[Thread 0x7fffda45b700 (LWP 28785) exited]
[Thread 0x7fffd3cd3700 (LWP 28786) exited]
[New Thread 0x7fffd3cd3700 (LWP 28787)]
[New Thread 0x7fffda45b700 (LWP 28788)]
[Thread 0x7fffd3cd3700 (LWP 28787) exited]
[Thread 0x7fffda45b700 (LWP 28788) exited]
[New Thread 0x7fffda45b700 (LWP 28789)]
[Thread 0x7fffda45b700 (LWP 28789) exited]
[New Thread 0x7fffda45b700 (LWP 28790)]
[Thread 0x7fffda45b700 (LWP 28790) exited]
[New Thread 0x7fffda45b700 (LWP 28791)]
[New Thread 0x7fffd3cd3700 (LWP 28792)]
[Thread 0x7fffda45b700 (LWP 28791) exited]
[New Thread 0x7fffd34d2700 (LWP 28794)]
[Thread 0x7fffd3cd3700 (LWP 28792) exited]
[Thread 0x7fffd34d2700 (LWP 28794) exited]
^C
Program received signal SIGINT, Interrupt.
0x00007fffe1e5ba60 in QMutex::unlock () from /usr/lib/libokularcore.so.1abi1

(gdb) info threads
  Id   Target Id         Frame
  10   Thread 0x7fffd9c5a700 (LWP 28776) "threaded-ml" 0x00007ffff20f0b03 in __GI___poll (fds=<optimized out>, nfds=<optimized out>, timeout=<optimized out>)
    at ../sysdeps/unix/sysv/linux/poll.c:87
  5    Thread 0x7fffd882b700 (LWP 28771) "chromium-browse" 0x00007ffff20f5823 in select () at ../sysdeps/unix/syscall-template.S:82
  2    Thread 0x7fffed253700 (LWP 28768) "Chrome_ChildIOT" syscall ()
    at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:39
* 1    Thread 0x7ffff7fa3980 (LWP 28765) "chromium-browse" 0x00007fffe1e5ba60 in QMutex::unlock () from /usr/lib/libokularcore.so.1abi1

(gdb) bt
#0  0x00007fffe1e5ba60 in QMutex::unlock ()
   from /usr/lib/libokularcore.so.1abi1
#1  0x00007fffe1e8108f in Okular::Document::closeDocument (this=0x55555a7683e0)
    at ../core/document.cpp:1786
#2  0x00007fffe213d189 in Okular::Part::closeUrl (this=0x55555a0dc840)
    at ../part.cpp:1337
#3  0x00007fffe213d7a8 in Okular::Part::~Part (this=0x55555a0dc840,
    __in_chrg=<optimized out>, __vtt_parm=<optimized out>) at ../part.cpp:774
#4  0x00007fffe213d809 in Okular::Part::~Part (this=0x55555a0dc840,
    __in_chrg=<optimized out>, __vtt_parm=<optimized out>) at ../part.cpp:799
#5  0x00007fffead0c097 in PartWin::~PartWin (this=0x55555a390680,
    __in_chrg=<optimized out>, __vtt_parm=<optimized out>)
    at /home/robert/devel/okularplugin/partwin.cpp:124
#6  0x00007fffead0c229 in PartWin::~PartWin (this=0x55555a390680,
    __in_chrg=<optimized out>, __vtt_parm=<optimized out>)
    at /home/robert/devel/okularplugin/partwin.cpp:130
#7  0x00007fffead0f042 in NPP_Destroy (instance=0x55555a4da760)
    at /home/robert/devel/okularplugin/qtbrowserplugin/qtbrowserplugin.cpp:970
#8  NPP_Destroy (instance=0x55555a4da760)
    at /home/robert/devel/okularplugin/qtbrowserplugin/qtbrowserplugin.cpp:960
#9  0x0000555557785f9d in ?? ()
#10 0x0000555557fb45a9 in ?? ()
#11 0x0000555557fb4c3c in ?? ()
#12 0x0000555557fb4d39 in ?? ()
#13 0x0000555557fb4358 in ?? ()
#14 0x0000555557b3dd57 in ?? ()
#15 0x0000555557b3df19 in ?? ()
#16 0x0000555557b3c779 in ?? ()
#17 0x0000555557b3c470 in ?? ()
#18 0x0000555557e14637 in ?? ()
#19 0x0000555557b3b8b5 in ?? ()
#20 0x0000555556a9ac9a in ?? ()
#21 0x000055555635e0a9 in ?? ()
#22 0x00005555563616fb in ?? ()
#23 0x0000555556361d03 in ?? ()
#24 0x000055555638e119 in ?? ()
#25 0x000055555638e15d in ?? ()
#26 0x00007ffff697cd53 in g_main_context_dispatch ()
   from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#27 0x00007ffff697d0a0 in ?? () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#28 0x00007ffff697d164 in g_main_context_iteration ()
   from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#29 0x000055555638de2f in ?? ()
#30 0x000055555635d810 in ?? ()
#31 0x0000555557b3a4b4 in ?? ()
#32 0x000055555632a378 in ?? ()
#33 0x0000555555ac7968 in ?? ()
#34 0x0000555555ac5e06 in ?? ()
#35 0x00007ffff202b76d in __libc_start_main (main=0x555555ac5e00, argc=5,
    ubp_av=0x7fffffffddb8, init=<optimized out>, fini=<optimized out>,
    rtld_fini=<optimized out>, stack_end=0x7fffffffdda8) at libc-start.c:226
#36 0x0000555555ac786d in ?? ()
#37 0x00007fffffffdda8 in ?? ()
#38 0x000000000000001c in ?? ()
#39 0x0000000000000005 in ?? ()
#40 0x00007fffffffe12f in ?? ()
#41 0x0000000000000000 in ?? ()

(gdb) thread 2
[Switching to thread 2 (Thread 0x7fffed253700 (LWP 28768))]
#0  syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:39
39      ../sysdeps/unix/sysv/linux/x86_64/syscall.S: Datei oder Verzeichnis nicht gefunden.

(gdb) bt
#0  syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:39
#1  0x000055555639c24a in ?? ()
#2  0x000055555639bce1 in ?? ()
#3  0x0000555556399d85 in ?? ()
#4  0x000055555633e5cd in ?? ()
#5  0x000055555635d810 in ?? ()
#6  0x000055555637d96c in ?? ()
#7  0x000055555637b572 in ?? ()
#8  0x00007ffff449be9a in start_thread (arg=0x7fffed253700)
    at pthread_create.c:308
#9  0x00007ffff20fc4bd in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#10 0x0000000000000000 in ?? ()

(gdb) thread 5
[Switching to thread 5 (Thread 0x7fffd882b700 (LWP 28771))]
#0  0x00007ffff20f5823 in select () at ../sysdeps/unix/syscall-template.S:82
82      ../sysdeps/unix/syscall-template.S: Datei oder Verzeichnis nicht gefunden.

(gdb) bt
#0  0x00007ffff20f5823 in select () at ../sysdeps/unix/syscall-template.S:82
#1  0x00007fffe8f71366 in qt_safe_select(int, fd_set*, fd_set*, fd_set*, timeval const*) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#2  0x00007fffe8f767b2 in QEventDispatcherUNIXPrivate::doSelect(QFlags<QEventLoop::ProcessEventsFlag>, timeval*) ()
   from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#3  0x00007fffe8f76ca3 in QEventDispatcherUNIX::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#4  0x00007fffe8f43c82 in QEventLoop::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#5  0x00007fffe8f43ed7 in QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#6  0x00007fffe8e42fa7 in QThread::exec() ()
   from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#7  0x00007fffe8f239ff in ?? () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#8  0x00007fffe8e45fcb in ?? () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#9  0x00007ffff449be9a in start_thread (arg=0x7fffd882b700)
    at pthread_create.c:308
#10 0x00007ffff20fc4bd in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#11 0x0000000000000000 in ?? ()

(gdb) thread 10
[Switching to thread 10 (Thread 0x7fffd9c5a700 (LWP 28776))]
#0  0x00007ffff20f0b03 in __GI___poll (fds=<optimized out>,
    nfds=<optimized out>, timeout=<optimized out>)
    at ../sysdeps/unix/sysv/linux/poll.c:87
87      ../sysdeps/unix/sysv/linux/poll.c: Datei oder Verzeichnis nicht gefunden.

(gdb) bt
#0  0x00007ffff20f0b03 in __GI___poll (fds=<optimized out>,
    nfds=<optimized out>, timeout=<optimized out>)
    at ../sysdeps/unix/sysv/linux/poll.c:87
#1  0x00007fffe116435f in ?? () from /usr/lib/x86_64-linux-gnu/libpulse.so.0
#2  0x00007fffe115576c in pa_mainloop_poll ()
   from /usr/lib/x86_64-linux-gnu/libpulse.so.0
#3  0x00007fffe1155dd9 in pa_mainloop_iterate ()
   from /usr/lib/x86_64-linux-gnu/libpulse.so.0
#4  0x00007fffe1155e90 in pa_mainloop_run ()
   from /usr/lib/x86_64-linux-gnu/libpulse.so.0
#5  0x00007fffe116430f in ?? () from /usr/lib/x86_64-linux-gnu/libpulse.so.0
#6  0x00007fffe0837d18 in ?? ()
   from /usr/lib/x86_64-linux-gnu/libpulsecommon-1.1.so
#7  0x00007ffff449be9a in start_thread (arg=0x7fffd9c5a700)
    at pthread_create.c:308
#8  0x00007ffff20fc4bd in clone ()
    at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112
#9  0x0000000000000000 in ?? ()

(gdb) cont
Continuing.

When I interrupt it a second time, it's locking the mutex, above it was unlocking it.

^C
Program received signal SIGINT, Interrupt.
[Switching to Thread 0x7ffff7fa3980 (LWP 28765)]
0x00007fffe8e40952 in QMutex::lock() ()
   from /usr/lib/x86_64-linux-gnu/libQtCore.so.4

(gdb) bt
#0  0x00007fffe8e40952 in QMutex::lock() ()
   from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#1  0x00007fffe1e81074 in Okular::Document::closeDocument (this=0x55555a7683e0)
    at ../core/document.cpp:1784
#2  0x00007fffe213d189 in Okular::Part::closeUrl (this=0x55555a0dc840)
    at ../part.cpp:1337
#3  0x00007fffe213d7a8 in Okular::Part::~Part (this=0x55555a0dc840,
    __in_chrg=<optimized out>, __vtt_parm=<optimized out>) at ../part.cpp:774
#4  0x00007fffe213d809 in Okular::Part::~Part (this=0x55555a0dc840,
    __in_chrg=<optimized out>, __vtt_parm=<optimized out>) at ../part.cpp:799
#5  0x00007fffead0c097 in PartWin::~PartWin (this=0x55555a390680,
    __in_chrg=<optimized out>, __vtt_parm=<optimized out>)
    at /home/robert/devel/okularplugin/partwin.cpp:124
#6  0x00007fffead0c229 in PartWin::~PartWin (this=0x55555a390680,
    __in_chrg=<optimized out>, __vtt_parm=<optimized out>)
    at /home/robert/devel/okularplugin/partwin.cpp:130
#7  0x00007fffead0f042 in NPP_Destroy (instance=0x55555a4da760)
    at /home/robert/devel/okularplugin/qtbrowserplugin/qtbrowserplugin.cpp:970
#8  NPP_Destroy (instance=0x55555a4da760)
    at /home/robert/devel/okularplugin/qtbrowserplugin/qtbrowserplugin.cpp:960
#9  0x0000555557785f9d in ?? ()
#10 0x0000555557fb45a9 in ?? ()
#11 0x0000555557fb4c3c in ?? ()

(gdb) cont
Continuing.

And a third interruption. This time, some event handling is going on, but it's still sitting in closeDocument():

^C
Program received signal SIGINT, Interrupt.
0x00007fffe8f43e2e in QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>)
    () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4

(gdb) bt
#0  0x00007fffe8f43e2e in QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#1  0x00007fffe1e818e2 in Okular::Document::closeDocument (this=0x55555a7683e0)
    at ../core/document.cpp:1790
#2  0x00007fffe213d189 in Okular::Part::closeUrl (this=0x55555a0dc840)
    at ../part.cpp:1337
#3  0x00007fffe213d7a8 in Okular::Part::~Part (this=0x55555a0dc840,
    __in_chrg=<optimized out>, __vtt_parm=<optimized out>) at ../part.cpp:774
#4  0x00007fffe213d809 in Okular::Part::~Part (this=0x55555a0dc840,
    __in_chrg=<optimized out>, __vtt_parm=<optimized out>) at ../part.cpp:799
#5  0x00007fffead0c097 in PartWin::~PartWin (this=0x55555a390680,
    __in_chrg=<optimized out>, __vtt_parm=<optimized out>)
    at /home/robert/devel/okularplugin/partwin.cpp:124
#6  0x00007fffead0c229 in PartWin::~PartWin (this=0x55555a390680,
    __in_chrg=<optimized out>, __vtt_parm=<optimized out>)
    at /home/robert/devel/okularplugin/partwin.cpp:130
#7  0x00007fffead0f042 in NPP_Destroy (instance=0x55555a4da760)
    at /home/robert/devel/okularplugin/qtbrowserplugin/qtbrowserplugin.cpp:970
#8  NPP_Destroy (instance=0x55555a4da760)
    at /home/robert/devel/okularplugin/qtbrowserplugin/qtbrowserplugin.cpp:960
#9  0x0000555557785f9d in ?? ()
#10 0x0000555557fb45a9 in ?? ()
#11 0x0000555557fb4c3c in ?? ()

[afrimberger]

Looks like this is a race condition in Okular. Still can't reproduce the bug, what makes it extremely hard to track down. The following patch is just a random shot, but maybe it fixes this issue:

diff --git a/partwin.cpp b/partwin.cpp
index 841708a..d6de4b5 100644
--- a/partwin.cpp
+++ b/partwin.cpp
@@ -117,11 +117,12 @@ void PartWin::setupActions() {

 PartWin::~PartWin()
 {
+  m_part->closeUrl();

   this->guiFactory()->removeClient(m_part);
   this->guiFactory()->removeClient(this);

-  delete m_part;
+  //delete m_part;

   QDir d;
   for( QList<QString>::const_iterator i = m_filesToDelete.begin(); i != m_filesToDelete.end(); ++i ) {
'''

Can you please try it and report back?

[rhuitl]

Nope, doesn't fix it, now it freezes at m_part->closeURL(). I also think this is a problem in Okular... do you know if the document open and closeUrl() are called from the same thread? Are you testing on a machine with multi-core support (mine has 2 cores + hyperthreading)?

[afrimberger]

Okay, would have been too easy :). The both methods openDocument() and closeDocument() are called from the same thread. I set some breakpoints to verify this. This means the speedy chromium is not the cause ;-).
Okular itself uses massive multithreading for rendering. This is why you see all those "New Thread" and "Thread exited" messages in the gdb output.

My assumption is, that m_executingPixmapRequests.isEmpty() always returns false and because of that the execution stucks in that do-while-loop (document.cpp:1781):

    bool startEventLoop = false;
    do
    {
        d->m_pixmapRequestsMutex.lock();
        startEventLoop = !d->m_executingPixmapRequests.isEmpty();
        d->m_pixmapRequestsMutex.unlock();
        if ( startEventLoop )
        {
            d->m_closingLoop = &loop;
            loop.exec();
            d->m_closingLoop = 0;
        }
    }
    while ( startEventLoop );

So the question is: Why does m_executingPixmapRequests get emptied in some cases and in others not?

Looks like we're testing nearly on the same hardware. Mine has a Core i7 with 2 cores and 2 virtual cores for hyperthreading.