Browsing the SSHFS-mounted directory in a "Save file"-dialog does not crash an application.

I tried it creating a new file in Kwrite and saving it on the SSHS-mounted directory.
I can enter and leave different directoriess (a few levels deep).

Hope this helps :)

(In reply to comment #1)
> Browsing the SSHFS-mounted directory in a "Save file"-dialog does not crash
> an application.
> 
> I tried it creating a new file in Kwrite and saving it on the SSHS-mounted
> directory.
> I can enter and leave different directoriess (a few levels deep).
> 
> Hope this helps :)

Hmm, from the looks of the backtrace it crashed in a folder that has version control in it. Could you verify that? So, it should crash on one of your folders with version control (cvs?) in it.

If it does, we need the folder to fix it :) You can remove everything out the folder till it's as small as possible and still crashing.

(In reply to comment #2)
> Hmm, from the looks of the backtrace it crashed in a folder that has version
> control in it.

Yes, it contains a working copy of a subversion repo.

> Could you verify that? So, it should crash on one of your
> folders with version control (cvs?) in it.

Additional details i know so far:

I tried to sshfs-mount a locale copy of the same repo.
When i browse this copy on localhost, dolphin does not crash.

I also tried to sshfs-mount another remote server, which contains some git-repos.
Againg, dolphin does not crash.

> If it does, we need the folder to fix it :)
> You can remove everything out
> the folder till it's as small as possible and still crashing.

ok :)

Oke, so it occurs only on mounted SSHFS partitions with a version controlled folder.. ehhh, not everyone has a SSHFS mount which makes this a bit difficult to fix ;)

(In reply to comment #4)
> Oke, so it occurs only on mounted SSHFS partitions with a version controlled
> folder.. ehhh, not everyone has a SSHFS mount which makes this a bit
> difficult to fix ;)

I will try to put a minimal working ( = crashing) example on my server. If this works, i will come back and ask you for your public key so you can access the example and hopefully reproduce the bug.

(In reply to comment #5)
> (In reply to comment #4)
> > Oke, so it occurs only on mounted SSHFS partitions with a version controlled
> > folder.. ehhh, not everyone has a SSHFS mount which makes this a bit
> > difficult to fix ;)
> 
> I will try to put a minimal working ( = crashing) example on my server. If
> this works, i will come back and ask you for your public key so you can
> access the example and hopefully reproduce the bug.

Hi,

I appreciate that effort :) Must be quite a job to get that "working" (read crashing). However, i don't have anything i can mount as SSHFS... yet. I can see if i can mount my local server though i rather prefer something less critical since i'm going to attempt dolphin crashes.. Even though that will not crash my server, it "might" cause some data loss which i rather prevent.

I'm seeing a crash that looks similar with 4.9rc2, when browsing an sshfs mounted folder in dolphin, containing a git repo. 

It only crashes if the dolphin git plugin is enabled, and it only crashes on first access; after the crash I can restart dolphin and list the folder fine.

I have the svn plugin turned off.

Does that agree with what you see?

Resetting assignee to default as per bug #305719

Created attachment 74459 [details]
New crash information added by DrKonqi

dolphin (2.0) on KDE Platform 4.8.5 (4.8.5) using Qt 4.8.1

- What I was doing when the application crashed:
I had this crash in slightly different circumstances. I had Dolphin in split screen mode, with a local bzr-controlled directory on one side and a network directory (mounted using sshfs/autofs) on the other. It happened while I was compiling a LaTeX document in the former directory (so quite a few files were changing at once). I should mention I have the bzr vcs plugin running in Dolphin.

It does not happen all the time.

-- Backtrace (Reduced):
#6  0x00007fb03a1a8752 in lockInline (this=0x1628990) at /usr/include/qt4/QtCore/qmutex.h:187
#7  relock (this=<synthetic pointer>) at /usr/include/qt4/QtCore/qmutex.h:129
#8  UpdateItemStatesThread::run (this=0x1628970) at ../../../dolphin/src/views/versioncontrol/updateitemstatesthread.cpp:67
#9  0x00007fb037d8cfcb in QThreadPrivate::start (arg=0x1628970) at thread/qthread_unix.cpp:298
#10 0x00007fb0336cfe9a in start_thread (arg=0x7fb017c6d700) at pthread_create.c:308

Created attachment 74465 [details]
Patch to hopefully fix the crash

I *think* the problem here is that the lock on the list of directory items being released when listing directories. Either due to a misplaced compiler optimisation, or something else, this pattern:

lock
..stuff..
const QString directory = getDirectory_from_data_which_may_be_changed_by_another_thread()
unlock
accessDirectory(directory)
relock

is being changed to:

lock
..stuff..
unlock
accessDirectory(getDirectory_from_data_which_may_be_changed_by_another_thread())
relock

and the other-thread data is being changed while the directory is being listed, causing the crash. 

The reason people are finding this with network filesystems is just that directory listing is much slower, so the window to hit the race is wider.

Solution is easy: just hold the lock over the call to accessdirectory. There's no real reason not to, especially since we are editing the data it is supposed to protect outside the lock. In most cases the overhead to release and get the lock compared with the directory listing time means this version is probably even faster. 

I haven't seen the crash with this patch, but it's always been intermittent, so if someone else could confirm, that would be good.

Thanks for the analysis and the patch!

The backtraces look like there is a deadlock between both threads:

Thread 1 is in UpdateItemStatesThread::setData() in line 51 in updateitemstatesthread.cpp. This means that it has the lock on m_itemMutex and tries to get the lock on m_globalPluginMutex.

Thread 2 is in UpdateItemStatesThread::run() in line 67 in updateitemstatesthread.cpp. This means that it has the lock on m_globalPluginMutex and tries to get the lock on m_itemMutex.

Your patch will indeed fix that because it prevents that thread 1 locks m_itemMutex in the small window (which might not be so small for remote file systems) where thread 2 releases the lock.

The only thing that is not clear to me is why this window actually exists - maybe there is a reason to unlock and re-lock the mutex, but I don't see it. An alternative fix would be to change UpdateItemStatesThread::setData() and unlock the first mutex before locking the other one. What do you think? I don't really think that access to shared data in the window where the lock is released is the problem.

Ah - yes, that makes more sense. It didn't occur to me that a deadlock could result in a segfault, actually. I thought it would just hang forever.

Releasing the lock earlier in setData would still (in principle) allow the formation of deadlocks, would it not? Because the locks are potentially taken in a different order. 

Suppose Thread A (in setData) gets itemMutex on line 50, and at the same time
Thread B gets PluginMutex on line 63. 

Then Thread B will try to re-lock itemMutex on line 65 and block because of thread A, while thread A tries to get PluginMutex on line 52 and blocks because of thread B. Deadlock!

I admit that I don't see why the window exists either though, which is troubling...

Thanks for the quick response

Sorry for the late reply, I was away for a couple of days.

(In reply to comment #12)
> Ah - yes, that makes more sense. It didn't occur to me that a deadlock could
> result in a segfault, actually. I thought it would just hang forever.

Why it segfaults is not really clear to me either, but the potential deadlock is the only problem that I can see in the code.

> Releasing the lock earlier in setData would still (in principle) allow the
> formation of deadlocks, would it not? Because the locks are potentially
> taken in a different order. 

I don't think that the locks can be done in a different order. When the compiler reorders statements to optimise the code, it must make sure that the reordered code is semantically equivalent. This would not be the case if mutex locks were reordered - the compiler would generate artificial deadlocks all the time if that was possible.

> Suppose Thread A (in setData) gets itemMutex on line 50, and at the same time
> Thread B gets PluginMutex on line 63. 
> 
> Then Thread B will try to re-lock itemMutex on line 65 and block because of
> thread A, while thread A tries to get PluginMutex on line 52 and blocks
> because of thread B. Deadlock!

This would not be possible if the first mutex was unlocked in setData() before the second one is locked.

> I admit that I don't see why the window exists either though, which is
> troubling...

Probably this is done to make sure that m_itemMutex is unlocked while "m_plugin->beginRetrieval(directory)" is executed in run(), because this call could take quite some time? If m_itemMutex would be locked during this call, any access to UpdateItemStatesThread::itemStates() or UpdateItemStatesThread::retrievedItems() from thread 1 might block the GUI.

> Sorry for the late reply, I was away for a couple of days.

That's alright - no need to apologise.

> Why it segfaults is not really clear to me either, but the potential
> deadlock is the only problem that I can see in the code.

One other thing I noticed - we have:

Q_ASSERT(!m_itemStates.isEmpty());
followed by:
m_itemStates.first()

but Q_ASSERT just prints a warning and continues if it is hit
(and in any case m_itemStates is not locked at the time),
so it doesn't seem impossible that m_itemStates is empty when .first() is called.

And actually, if m_plugin is null, we will give a warning and segfault, so maybe that's the problem.

> > Releasing the lock earlier in setData would still (in principle) allow the
> > formation of deadlocks, would it not? Because the locks are potentially
> > taken in a different order. 
> 
> I don't think that the locks can be done in a different order. When the
> compiler reorders statements to optimise the code, it must make sure that
> the reordered code is semantically equivalent. This would not be the case if
> mutex locks were reordered - the compiler would generate artificial
> deadlocks all the time if that was possible.

Sorry, I wasn't very clear - I just meant "sometimes itemMutex is taken first, and sometimes PluginMutex", not that they could be taken in a different order to that written in the code.

> > Suppose Thread A (in setData) gets itemMutex on line 50, and at the same time
> > Thread B gets PluginMutex on line 63. 
> > 
> > Then Thread B will try to re-lock itemMutex on line 65 and block because of
> > thread A, while thread A tries to get PluginMutex on line 52 and blocks
> > because of thread B. Deadlock!
> 
> This would not be possible if the first mutex was unlocked in setData()
> before the second one is locked.

You're quite right, that would fix it. I was worried that if run() were 
called after unlocking the first mutex in setData, but before locking the second, 
m_itemStates could get listings from the old plugin. 
We could fix that by just taking PluginMutex first in setData though.

> > I admit that I don't see why the window exists either though, which is
> > troubling...
> 
> Probably this is done to make sure that m_itemMutex is unlocked while
> "m_plugin->beginRetrieval(directory)" is executed in run(), because this
> call could take quite some time? If m_itemMutex would be locked during this
> call, any access to UpdateItemStatesThread::itemStates() or
> UpdateItemStatesThread::retrievedItems() from thread 1 might block the GUI.

Makes sense. So what do you think of the following patch?

Created attachment 74568 [details]
Patch with even more hope of fixing the crash

This patch:
- Fixes potential deadlocks by taking the two mutexes in setData in the same order as in run(). 
- Fixes potential segfaults by checking explicitly under a mutex that m_plugin is not null and m_itemStates is not empty and returning if they are.

- Hopefully fixes the crash.

Thanks for the updated patch! Can be pushed to 4.9 after considering the comments below. If you don't have a git account, let me know and I'll do it for you.

+    //The locks are taken in the same order as in run()
+    //to avoid potential deadlock.

Add a space after '//' - that is more consistent with existing code and improves readability.

+    QMutexLocker pluginLocker(m_globalPluginMutex);
     QMutexLocker itemLocker(&m_itemMutex);
-    m_itemStates = itemStates;
 
-    QMutexLocker pluginLocker(m_globalPluginMutex);
+    m_itemStates = itemStates;
     m_plugin = plugin;
 
Yes, that might be a good way to fix the crash. 
 
@@ -58,12 +60,15 @@ void UpdateItemStatesThread::run()
     Q_ASSERT(m_plugin);
 
     QMutexLocker itemLocker(&m_itemMutex);
+    if ( m_itemStates.isEmpty() )
+        return;

Not necessary - the Q_ASSERT() at the beginning of that function ensures that m_itemStates is not empty.

     const QString directory = m_itemStates.first().item.url().directory(KUrl::AppendTrailingSlash);
+    m_retrievedItems = false;
     itemLocker.unlock();

Right, m_retrievedItems should also be protected by the mutex, good catch!
 
-    if (m_plugin->beginRetrieval(directory)) {
+    if (m_plugin && m_plugin->beginRetrieval(directory)) {

m_plugin cannot be 0 (see Q_ASSERT() in that function).

> Thanks for the updated patch! Can be pushed to 4.9 after considering the
> comments below. If you don't have a git account, let me know and I'll do it
> for you.

Thanks! I have a git account, and I'll go ahead and commit it to 4.9.

> Add a space after '//' - that is more consistent with existing code and
> improves readability.

Sure.

> Not necessary - the Q_ASSERT() at the beginning of that function ensures
> that m_itemStates is not empty.

Ok - I was just being paranoid.

Strange, why isn't there auto message for http://commits.kde.org/kde-baseapps/4bdf134cbd3543fbf0273ed49e2b13b3ce49744e  ?

commit 4bdf134cbd3543fbf0273ed49e2b13b3ce49744e
Author: Simeon Bird <spb@ias.edu>
Date:   22 分钟之前

    Fix race condition and deadlock in the version plugin
    when listing directories is slow.
    
    BUG: 302264
    FIXED-IN: 4.9.3

Sorry, I committed from the wrong email address...

Ok, actually, this isn't fixed at all (I was able to trigger it fairly reliably again).

So, simply not unlocking and relocking the mutex does indeed appear to fix the crash, but I think by accident; not unlocking the mutex means that calls to itemState block while UpdateStateThread::run is in progress, and thus slotThreadFinished is blocked. 

If slotThreadFinished is not blocked, once it is done deleteLater() is called on the UpdateStateThread. When I compile in debug mode I get a "QThread:destroyed while thread is still running" message before the crash. So I think that somehow this deletion event is getting delivered to the running UpdateStateThread, not the one that just finished. 

FYI, I can trigger this reliably if I make the itemMutex a ReadWriteLock.

The call to setData is a red herring: it's just sitting there blocking in another thread, not doing anything dangerous.

Git commit a9d7ebbc8be0d03104f3b5c620f8da232cd52857 by Simeon Bird.
Committed on 13/01/2013 at 19:49.
Pushed by sbird into branch 'KDE/4.10'.

A crash occurs if updateItemStates runs between the
UpdateItemStatesThread finishing and the finished() signal being
delivered.

In this case, a new thread was not created, because the old thread
still existed. However, pendingItemStatesUpdate was not set, because the
thread was not running. Instead, the old thread was restarted.

This meant that the finished() signal from the first run could be delivered
while the thread was running for a second time, causing the thread to be
deleted while still running and thus a crash.

Solution: set pendingItemStatesUpdate if the thread is non-null,
even if it is not running, knowing that slotThreadFinished has not yet run,
and will call updateItemStates itself.
FIXED-IN: 4.10
REVIEW: 107656

M  +1    -1    dolphin/src/views/versioncontrol/versioncontrolobserver.cpp

http://commits.kde.org/kde-baseapps/a9d7ebbc8be0d03104f3b5c620f8da232cd52857