Crash in "Attempted to connect a connection that is not disconnected" #2353

Closed
dmoagx opened this Issue Dec 6, 2015 · 3 comments

Projects

None yet

1 participant

@dmoagx
Collaborator
dmoagx commented Dec 6, 2015

Since fixing the other top crash issues, this seems to be the new top crash issue in nightlies.
For example:

Crashed Thread:        12

Exception Type:        EXC_BAD_INSTRUCTION (SIGILL)
Exception Codes:       0x0000000000000001, 0x0000000000000000
Exception Note:        EXC_CORPSE_NOTIFY

Application Specific Information:
Attempted to connect a connection that is not disconnected (SPMySQLConnectionState=2).

(...)

Thread 12 Crashed:
0   com.sequelpro.spmysql           0x0000000100387938 -[SPMySQLConnection(PrivateAPI) _connect] + 664
1   com.sequelpro.spmysql           0x0000000100387025 -[SPMySQLConnection connect] + 28
2   com.sequelpro.SequelPro         0x000000010013e8e1 -[SPDatabaseStructure(Private_API) _ensureConnectionUnsafe] + 198
3   com.sequelpro.SequelPro         0x000000010013edaf -[SPDatabaseStructure(Private_API) _checkConnection] + 202
4   com.sequelpro.SequelPro         0x000000010013d9db -[SPDatabaseStructure queryDbStructureWithUserInfo:] + 3109
5   com.apple.Foundation            0x00007fff8e812ee4 __NSThread__start__ + 1351
6   libsystem_pthread.dylib         0x00007fff8a22b9b1 _pthread_body + 131
7   libsystem_pthread.dylib         0x00007fff8a22b92e _pthread_start + 168
8   libsystem_pthread.dylib         0x00007fff8a229385 thread_start + 13

Thread 13:: SPDatabaseViewController table load task (SPDatabaseDocument#3)
0   libsystem_kernel.dylib          0x00007fff938c2f5e __psynch_cvwait + 10
1   libsystem_pthread.dylib         0x00007fff8a22c73d _pthread_cond_wait + 767
2   com.apple.Foundation            0x00007fff8e813048 -[NSCondition wait] + 240
3   com.apple.Foundation            0x00007fff8e81201a -[NSObject(NSThreadPerformAdditions) performSelector:onThread:withObject:waitUntilDone:modes:] + 935
4   com.apple.Foundation            0x00007fff8e811bf5 -[NSObject(NSThreadPerformAdditions) performSelectorOnMainThread:withObject:waitUntilDone:] + 131
5   com.sequelpro.SequelPro         0x00000001000f9fde -[SPMainThreadTrampoline forwardInvocation:] + 153
6   com.apple.CoreFoundation        0x00007fff9a8b5472 ___forwarding___ + 514
7   com.apple.CoreFoundation        0x00007fff9a8b51e8 _CF_forwarding_prep_0 + 120
8   com.sequelpro.SequelPro         0x000000010014cd6b -[SPTableStructure(SPTableStructureLoading) loadTable:] + 891
9   com.sequelpro.SequelPro         0x0000000100123bfe -[SPDatabaseDocument(SPDatabaseViewControllerPrivateAPI) _loadTableTask] + 1058
10  com.apple.Foundation            0x00007fff8e812ee4 __NSThread__start__ + 1351
11  libsystem_pthread.dylib         0x00007fff8a22b9b1 _pthread_body + 131
12  libsystem_pthread.dylib         0x00007fff8a22b92e _pthread_start + 168
13  libsystem_pthread.dylib         0x00007fff8a229385 thread_start + 13

(...)

Thread 15:
0   libsystem_kernel.dylib          0x00007fff938c32b2 __semwait_signal + 10
1   libsystem_c.dylib               0x00007fff9a221a75 nanosleep + 199
2   libsystem_c.dylib               0x00007fff9a221968 usleep + 54
3   com.sequelpro.SequelPro         0x000000010013ea65 -[SPDatabaseStructure(Private_API) _addToListAndWaitForFrontCancellingOtherThreads:] + 334
4   com.sequelpro.SequelPro         0x000000010013ce48 -[SPDatabaseStructure queryDbStructureWithUserInfo:] + 146
5   com.apple.Foundation            0x00007fff8e812ee4 __NSThread__start__ + 1351
6   libsystem_pthread.dylib         0x00007fff8a22b9b1 _pthread_body + 131
7   libsystem_pthread.dylib         0x00007fff8a22b92e _pthread_start + 168
8   libsystem_pthread.dylib         0x00007fff8a229385 thread_start + 13

This looks like a race condition between two background threads.

Usually there are multiple -[SPDatabaseStructure queryDbStructureWithUserInfo:] involved, so I already added some more restrictive locking code, but it looks like there is another code path involved in causing the crash (perhaps the -[SPDatabaseDocument(SPDatabaseViewControllerPrivateAPI) _loadTableTask] seen above).

Connection states for reference:

// Connection state
typedef enum {
    SPMySQLDisconnected               = 0,
    SPMySQLConnecting                 = 1,
    SPMySQLConnected                  = 2,
    SPMySQLConnectionLostInBackground = 3,
    SPMySQLDisconnecting              = 4
} SPMySQLConnectionState;
@dmoagx
Collaborator
dmoagx commented Dec 6, 2015

Popularity by state:

state count (including 1.1)
0 0 (0)
1 1 (58)
2 78 (84)
3 0 (0)
4 3 (53)
@dmoagx dmoagx added a commit that referenced this issue Jan 13, 2016
@dmoagx dmoagx Add more debug info for "Attempted to connect a connection that is no…
…t disconnected" crash (#2353)
5243f74
@dmoagx dmoagx added a commit that referenced this issue Jan 15, 2016
@dmoagx dmoagx Try to fix what could be the cause of #2353 ("Attempted to connect a …
…connection that is not disconnected")
3aadea1
@dmoagx
Collaborator
dmoagx commented Jan 15, 2016

I previously assumed this was a race condition, but the recent debug code shows that there are usually a few seconds between the last connection and the crash.

This let me to look at ways the code might enter [mysql connect] while bypassing a state check.

It turns out that in _ensureConnectionUnsafe

    // Check the connection state
    if ([mySQLConnection isConnected] && [mySQLConnection checkConnection]) return YES;

The second condition might fail if the thread is cancelled.
_ensureConnectionUnsafe does not check for that and thus, bypassing the result of the state check (first condition) tries to reconnect.

This fits rather well with the observation that there usually is a -[SPDatabaseStructure(Private_API) _addToListAndWaitForFrontCancellingOtherThreads:] on another thread while the crash occurs.

@dmoagx dmoagx added a commit that referenced this issue Feb 12, 2016
@dmoagx dmoagx Fix for #2353 ("Attempted to connect a connection that is not disconn…
…ected")

Backport of 3aadea1
4341c2a
@dmoagx dmoagx added this to the 1.1.1 milestone Feb 13, 2016
@dmoagx dmoagx modified the milestone: 1.1.1 Feb 20, 2016
@dmoagx
Collaborator
dmoagx commented Feb 20, 2016
@dmoagx dmoagx closed this Feb 20, 2016
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment