Deadlock when checking isDataAvailable and performing Query

[lkraider]

While trying to findObjectsInBackgroundWithBlock and checking isDataAvailable, the following can occur:

Main Thread:
#0  0x00000001984530c0 in __psynch_mutexwait ()
#1  0x00000001984ed494 in _pthread_mutex_lock ()
#2  0x00000001002a8f78 in -[PFObject state] at /Users/nlutsenko/src/parse/ios-client/Parse/PFObject.m:2047
#3  0x00000001002aab20 in -[PFObject isDataAvailable] at /Users/nlutsenko/src/parse/ios-client/Parse/PFObject.m:2341
...


Internal Parse NSOperationQueue Serial Thread:
#0  0x00000001984530c0 in __psynch_mutexwait ()
#1  0x00000001984ed494 in _pthread_mutex_lock ()
#2  0x00000001002a523c in -[PFObject(Private) _mergeAfterFetchWithResult:decoder:completeData:] at /Users/nlutsenko/src/parse/ios-client/Parse/PFObject.m:1587
...
#22 0x00000001002a12ac in +[PFObject(Private) _objectFromDictionary:defaultClassName:selectedKeys:] at /Users/nlutsenko/src/parse/ios-client/Parse/PFObject.m:1041
#23 0x00000001002c9724 in __78-[PFQueryController findObjectsAsyncForQueryState:withCancellationToken:user:]_block_invoke26 at /Users/nlutsenko/src/parse/ios-client/Parse/Internal/Query/Controller/PFQueryController.m:84
...
#59 0x00000001002f9db8 in -[PFTaskHTTPRequestOperation _operationDidFinish] at /Users/nlutsenko/src/parse/ios-client/Parse/Internal/HTTPRequest/PFTaskHTTPRequestOperation.m:51
#60 0x000000010028d16c in -[PFCommandNetworkOperation _operationDidFinish] at /Users/nlutsenko/src/parse/ios-client/Parse/Internal/HTTPRequest/PFCommandNetworkOperation.m:78
...
----------
Enqueued from Background Thread:
...
#3  0x00000001002de250 in -[PFRESTCommandRunner _runCommandAsync:withCancellationToken:] at /Users/nlutsenko/src/parse/ios-client/Parse/Internal/Commands/PFRESTCommandRunner.m:168
...
#7  0x00000001002c9398 in __78-[PFQueryController findObjectsAsyncForQueryState:withCancellationToken:user:]_block_invoke at /Users/nlutsenko/src/parse/ios-client/Parse/Internal/Query/Controller/PFQueryController.m:64
...
----------
Enqueued from Main Thread:
#0  0x0000000100743d50 in _dispatch_async_f_slow ()
#1  0x000000010030cf88 in -[BFExecutor execute:] at /Users/chrisp/src/ios-sdk-3/Bolts-IOS/Bolts/Common/BFExecutor.m:109
...
#19 0x00000001002bfaf8 in -[PFQuery findObjectsInBackgroundWithBlock:] at /Users/nlutsenko/src/parse/ios-client/Parse/PFQuery.m:806

[nlutsenko]

Hey @lkraider, thanks for the report.
Stack trace is super helpful... I'll look into this one.

[nlutsenko]

Can you also please check if you are running into the same issue on the latest SDK? 1.8.0.
There is quite a bit of things that changed since 1.7.5, specifically around these methods and how queries work.

[lkraider]

Just checking with 1.8.0, still getting deadlocks where two threads try to access [PFObject objectId] (in this case, one thread access local datastorage (parse.sqlite.db.queue serial thread), another loading from network (NSOperationQueue serial thread)).

[nlutsenko]

Thanks.
Any chance you have a repro project or a code snippet for this?
I've looked into the issue in the meantime and while stack trace is helpful (would be awesome to get one from 1.8.0 as well), specifically in this case it's somewhat hard to track it down, as I think it depends on the schema of your object (child objects if any, as well as fields on the object).

[lkraider]

Adding a new trace (3 threads deadlock):

Thread 1 Queue : com.apple.main-thread (serial)
#0  0x00000001984530c0 in __psynch_mutexwait ()
#1  0x00000001984ed494 in _pthread_mutex_lock ()
#2  0x00000001002a6198 in -[PFObject _state] ()
#3  0x00000001002a7b90 in -[PFObject isDataAvailable] ()
...



Thread 11 Queue : NSOperationQueue :: NSOperation (serial)
#0  0x00000001984530c0 in __psynch_mutexwait ()
#1  0x00000001984ed494 in _pthread_mutex_lock ()
#2  0x00000001002a6198 in -[PFObject _state] ()
#3  0x00000001002a63f8 in -[PFObject objectId] ()
#4  0x00000001002e99c8 in -[PFPointerOrLocalIdObjectEncoder encodeParseObject:] ()
...
#8  0x00000001002e7804 in +[PFJSONCacheItem cacheFromObject:] ()
...
#35 0x00000001002f4660 in __80-[PFCloudCodeController callCloudCodeFunctionAsync:withParameters:sessionToken:]_block_invoke_2 ()
...



Thread 37 Queue : com.parse.sqlite.db.queue (serial)
#0  0x00000001984530c0 in __psynch_mutexwait ()
#1  0x00000001984ed494 in _pthread_mutex_lock ()
#2  0x00000001002a6198 in -[PFObject _state] ()
#3  0x00000001002a63f8 in -[PFObject objectId] ()
#4  0x00000001002e9f30 in -[PFOfflineObjectEncoder encodeParseObject:] ()
...
#7  0x0000000100296aec in __59-[PFObjectState dictionaryRepresentationWithObjectEncoder:]_block_invoke ()
...
#10 0x0000000100296a50 in -[PFObjectState dictionaryRepresentationWithObjectEncoder:] ()
#11 0x000000010029fe90 in -[PFObject(Private) RESTDictionaryWithObjectEncoder:operationSetUUIDs:state:operationSetQueue:] ()
#12 0x000000010029fdb8 in -[PFObject(Private) RESTDictionaryWithObjectEncoder:operationSetUUIDs:] ()
#13 0x0000000100308e94 in __54-[PFOfflineStore saveObjectLocallyAsync:key:database:]_block_invoke261 ()
...
----------
Enqueued from com.parse.sqlite.db.queue (Thread 37) (serial)
...
#6  0x000000010031061c in -[PFSQLiteDatabase executeSQLAsync:withArgumentsInArray:] ()
#7  0x000000010030db50 in -[PFOfflineStore getOrCreateUUIDAsyncForObject:database:] ()
...
----------
Enqueued from com.parse.sqlite.db.queue (Thread 37) (serial)
...
#6  0x000000010031048c in -[PFSQLiteDatabase executeQueryAsync:withArgumentsInArray:] ()
#7  0x000000010030699c in -[PFOfflineStore fetchObjectLocallyAsync:database:] ()
#8  0x00000001003081ec in -[PFOfflineStore saveObjectLocallyAsync:withChildren:database:] ()
#9  0x0000000100307f84 in -[PFOfflineStore saveObjectLocallyAsync:includeChildren:database:] ()
...
----------
Enqueued from com.parse.sqlite.db.queue (Thread 37) (serial)
...
#6  0x000000010031061c in -[PFSQLiteDatabase executeSQLAsync:withArgumentsInArray:] ()
#7  0x000000010030ed64 in __60-[PFOfflineStore _performDatabaseTransactionAsyncWithBlock:]_block_invoke ()
#8  0x000000010030f064 in __58-[PFOfflineStore _performDatabaseOperationAsyncWithBlock:]_block_invoke ()
...
#16 0x00000001002ac7f4 in __56-[PFSQLiteDatabaseController openDatabaseWithNameAsync:]_block_invoke_2 ()
...
----------
Enqueued from com.apple.root.default-qos (Thread 11) (serial)
...
#6  0x000000010030f900 in -[PFSQLiteDatabase openAsync] ()
#7  0x00000001002ac65c in __56-[PFSQLiteDatabaseController openDatabaseWithNameAsync:]_block_invoke ()
...
----------
Enqueued from com.parse.asynctaskqueue.sync (Thread 35) (serial)
...
#6  0x00000001002817b8 in __28-[PFAsyncTaskQueue enqueue:]_block_invoke ()
...
----------
Enqueued from com.parse.object.pin.cache (Thread 0) (serial)
...
#1  0x000000010028171c in -[PFAsyncTaskQueue enqueue:] ()
#2  0x00000001002ac558 in -[PFSQLiteDatabaseController openDatabaseWithNameAsync:] ()
#3  0x000000010030ef74 in -[PFOfflineStore _performDatabaseOperationAsyncWithBlock:] ()
#4  0x0000000100309758 in -[PFOfflineStore findAsyncForQueryState:user:pin:isCount:] ()
#5  0x0000000100309450 in -[PFOfflineStore findAsyncForQueryState:user:pin:] ()
#6  0x00000001002e3df8 in __46-[PFPinningObjectStore fetchPinAsyncWithName:]_block_invoke_2 ()
...
#13 0x00000001002e3c84 in __46-[PFPinningObjectStore fetchPinAsyncWithName:]_block_invoke ()
...
----------
Enqueued from com.apple.main-thread (Thread 1) (serial)
...
#6  0x00000001002e3b1c in -[PFPinningObjectStore fetchPinAsyncWithName:] ()
#7  0x00000001002e4a14 in -[PFPinningObjectStore unpinAllObjectsAsyncWithPinName:] ()
#8  0x00000001002ab83c in +[PFObject unpinAllObjectsInBackgroundWithName:] ()
#9  0x00000001002ab78c in +[PFObject unpinAllObjectsInBackgroundWithName:block:] ()
...

[parse-github-bot]

This issue has not been updated for 7 days. If you have additional information to help pinpoint this issue as an SDK bug, please comment on this issue. We will close this issue in 7 days if no additional information is provided. Thank you for your feedback.

[nlutsenko]

@lkraider, thanks for the stack trace. I am marking this as needs investigation, so it won't get automatically closed.
From the stack trace - it looks like after #102 is merged in - the problem is going to be resolved.
Feel free to check out the branch attached to it and let me know if it works for you in the meantime.

[lkraider]

I am testing with that branch, I am now getting a deadlock with 100% CPU usage from a call on the main thread ending in PFPropertyInfo:

Thread 1 Queue : com.parse.object.subclassing.data.access (serial)
#0  in OSAtomicCompareAndSwap64Barrier ()
#1  in pthread_rwlock_unlock ()
#2  in property_copyAttributeValue ()
#3  in safeStringWithPropertyAttributeValue at Parse/Internal/PropertyInfo/PFPropertyInfo.m:19
#4  in -[PFPropertyInfo initWithClass:name:associationType:] at Parse/Internal/PropertyInfo/PFPropertyInfo.m:74
#5  in -[PFPropertyInfo initWithClass:name:] at Parse/Internal/PropertyInfo/PFPropertyInfo.m:47
#6  in +[PFPropertyInfo propertyInfoWithClass:name:] at Parse/Internal/PropertyInfo/PFPropertyInfo.m:123
#7  in -[PFObjectSubclassInfo _rawPropertyInfoForSelector:] at Parse/Internal/Object/Subclassing/PFObjectSubclassInfo.m:187
#8  in __61-[PFObjectSubclassInfo forwardingMethodSignatureForSelector:]_block_invoke at Parse/Internal/Object/Subclassing/PFObjectSubclassInfo.m:126
#9  in _dispatch_client_callout ()
#10 in _dispatch_barrier_sync_f_invoke ()
#11 in -[PFObjectSubclassInfo forwardingMethodSignatureForSelector:] at Parse/Internal/Object/Subclassing/PFObjectSubclassInfo.m:120
#12 in -[PFObjectSubclassingController forwardingMethodSignatureForSelector:ofClass:] at Parse/Internal/Object/Subclassing/PFObjectSubclassingController.m:175
#13 in +[PFObject resolveInstanceMethod:] at Parse/PFObject.m:2405
#14 in _class_resolveInstanceMethod(objc_class*, objc_selector*, objc_object*) ()
#15 in lookUpImpOrForward ()
#16 in _objc_msgSend_uncached_impcache ()

I am not sure where the other lock is coming from. This is from an property access in a PFObject subclass, example calling code in AppDelegate:

assertMainThread();
[[Crashlytics sharedInstance] setUserIdentifier:[UserManager sharedInstance].user.objectId];
[[Crashlytics sharedInstance] setUserName:[UserManager sharedInstance].user.name];
[[Crashlytics sharedInstance] setUserEmail:[UserManager sharedInstance].user.email]; // <-- deadlock here

Deadlock happens in the last line.

[nlutsenko]

Deadlock usually involves more than a single thread, a chance you can attach stack trace for all of them?

[richardjrossiii]

@lkraider Can you try with the latest master? #129 has improved the performance significantly with PFPropertyInfo.

[lkraider]

Created another situation, the full stack trace is here:
https://gist.github.com/lkraider/4accac93b273136f0c3b

Branch is nlutsenko.containers. I will be able to try the master branch next week.