Skip to content

Loading…

After CBLLiveQuery reports an existing docID, doc has no properties yet #104

Closed
tgogolin opened this Issue · 5 comments

3 participants

@tgogolin

See CouchbaseMobile thread on google groups "After CBLLiveQuery reports an existing docID, doc has no properties yet?"
https://groups.google.com/forum/?fromgroups=#!topic/mobile-couchbase/KNk7flVKCCs

Summary: When responding to a CBLLiveQuery searching for a specific UUID that has just been synced to a local device, an immediate attempt to make a CBLDocument inside the observeValueForKeyPath: @"rows" code will make a CBLDocument that has no properties dictionary. You must wait an unknown period of time before you can successfully make the CBLDocument with expected properties. Note that a delay of 0.0 (just to unwind the stack before attempting to make the CBLDocument) does NOT succeed. 2.0 seconds typically does succeed.

Expected behavior: I would expect that after CBLLiveQuery has reported the existence of a docID, that it would be safe to immediately fetch that CBLDocument and examine its properties. If that is not possible, a documented way of noting when it IS safe to fetch the document properties would be appreciated.

On Google groups thread, Jens said:
BEGIN QUOTE
Sounds like a CBL bug. Could you file an issue on Github, please? I think this is a problem with the ordering of notifications, i.e. your code is getting the live-query notification before the document gets notified that it has a new revision available. It would be helpful if you could include a stack backtrace at the point where your notification handler gets called; you can do this by setting a breakpoint there and then entering “bt” in the debug console when it’s hit.

As a temporary workaround, I think you can safely reduce the wait to 0 — this isn’t a no-op, it’ll cause the delayed block to run immediately after the runloop finishes handling the current event/notification, by which time the document should have been notified. That way at least there won’t be a user-visible lag.
END QUOTE

Note: reducing the delay to zero does NOT cause the CBLDocument to be built correctly; a more substantial delay seems to be required.

Note: DMObject is our data model class, its state is the properties dictionary from a CBLDocument.

Breakpoint ONE (main thread):
change notification from CBL causes us to look for a doc with a specified uuid,
but it isn't yet in the database, so we mark it as 'missing'.

#0  0x008eb9c8 in -[CouchBasedArchive reportMissingObject:] at .../hsdatamodel/src/CouchSerializer.mm:365
#1  0x0096546e in -[DMObjectUniverse reportMissingObject:] at .../hsdatamodel/src/DMObjectUniverse.mm:354
#2  0x008f7a54 in +[DMObject reportMissingObject:] at .../hsdatamodel/src/DMObject.mm:552
#3  0x00969c38 in -[<redacted> initWithStorageDictionary:] 
#4  0x008e76ba in -[CouchBasedArchive unarchiveObjectFromUUID:] at .../hsdatamodel/src/CouchSerializer.mm:135
#5  0x00965aaa in -[DMObjectUniverse objectExistsForUUID:] at .../hsdatamodel/src/DMObjectUniverse.mm:384
#6  0x00965f6a in -[DMObjectUniverse objectForUUID:] at .../hsdatamodel/src/DMObjectUniverse.mm:404
#7  0x008f6b24 in +[DMObject objectForUUID:] at .../hsdatamodel/src/DMObject.mm:516
...
#12 0x00962bbe in -[DMObjectObservationManager informObserversOfChangeToUUID:] at .../hsdatamodel/src/DMObjectUniverse.mm:226
#13 0x0096721a in -[DMObjectUniverse cblDocumentChangeNotification:] at .../hsdatamodel/src/DMObjectUniverse.mm:480
#14 0x311b0110 in __CFNOTIFICATIONCENTER_IS_CALLING_OUT_TO_AN_OBSERVER__ ()
#15 0x31124306 in _CFXNotificationPost ()
#16 0x009fba06 in -[CBLDocument revisionAdded:] at .../external-libs/cbl/Source/API/CBLDocument.m:158
#17 0x009fef12 in -[CBLDatabase postPublicChangeNotification:] at .../external-libs/cbl/Source/API/CBLDatabase.m:90
#18 0x0099cb46 in -[CBLDatabase(Internal) postChangeNotifications] at .../external-libs/cbl/Source/CBLDatabase+Internal.m:499
#19 0x0099bfb8 in -[CBLDatabase(Internal) endTransaction:] at .../external-libs/cbl/Source/CBLDatabase+Internal.m:421
#20 0x0099c100 in -[CBLDatabase(Internal) _inTransaction:] at .../external-libs/cbl/Source/CBLDatabase+Internal.m:437
#21 0x009c2f4c in -[CBL_Puller insertDownloads:] at .../external-libs/cbl/Source/CBL_Puller.m:473
#22 0x009bf206 in __30-[CBL_Puller beginReplicating]_block_invoke at .../external-libs/cbl/Source/CBL_Puller.m:71
#23 0x009d0cfe in -[CBLBatcher processNow] at .../external-libs/cbl/Source/CBLBatcher.m:70

Breakpoint TWO (main thread)
LiveQuery says object is found, via observeValueForKeyPath "rows"

#0  0x008ecfb8 in -[CouchBasedArchive checkMissingObjectQuery] at .../hsdatamodel/src/CouchSerializer.mm:435
#1  0x008ec856 in -[CouchBasedArchive observeValueForKeyPath:ofObject:change:context:] at .../hsdatamodel/src/CouchSerializer.mm:408
#2  0x31afcd30 in NSKeyValueNotifyObserver ()
#3  0x31afc9d4 in NSKeyValueDidChange ()
#4  0x31ae8fec in -[NSObject(NSKeyValueObserverNotification) didChangeValueForKey:] ()
#5  0x00a042de in __22-[CBLLiveQuery update]_block_invoke at .../external-libs/cbl/Source/API/CBLQuery.m:271
#6  0x00a03274 in __21-[CBLQuery runAsync:]_block_invoke_2 at .../external-libs/cbl/Source/API/CBLQuery.m:170
#7  0x00a28080 in -[NSObject(MYBlockUtils) my_run_as_block] at .../external-libs/cbl/vendor/MYUtilities/MYBlockUtils.m:22
#8  0x31bb153a in __NSThreadPerformPerform ()
#9  0x311b917a in __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__ ()
#10 0x311b864a in __CFRunLoopDoSources0 ()
#11 0x311b6e3e in __CFRunLoopRun ()
#12 0x31121cd6 in CFRunLoopRunSpecific ()
#13 0x31121aba in CFRunLoopRunInMode ()
#14 0x35b782da in GSEventRunModal ()
#15 0x33726120 in UIApplicationMain ()
#16 0x000c646a in main at .../main.m:14
-(void) checkMissingObjectQuery
{
    BOOL changedTheMissingObjectList = NO;
    CBLQueryEnumerator* rowEnum = self.observedLiveQueryForMissingObjects.rows;
    for(CBLQueryRow* aQueryRow in rowEnum)
    {
        NSString* uuid = aQueryRow.key;
        if([self.missingObjects containsObject:uuid])
        {
            changedTheMissingObjectList = YES;
            [self.missingObjects removeObject:uuid];

            // My LiveQuery has notified me that the uuid is now found, but does a CBLDocument actually have any properties?
            CBLDocument* aDoc = [_database documentWithID:uuid];
            NSDictionary* dict = aDoc.properties;
            NSLog(@"aDoc = %@", aDoc); // "aDoc = CBLDocument[1725..F05B]"
            NSLog(@"dict = %@", dict); // dict = (null)

            if(dict == nil)
            {
                // This hit the bug case, where the CBLDocument has no properties!
                // aDoc._currentRevision is NIL!
                NSLog(@"BUG!");
            }

            // Here's the hack workaround, 0.0 delay DOES NOT WORK (the doc still has a nil currentRevision)
            double delayInSeconds = 2.0;            
            dispatch_time_t popTime = dispatch_time(DISPATCH_TIME_NOW, (int64_t)(delayInSeconds * NSEC_PER_SEC));
            dispatch_after(popTime, dispatch_get_main_queue(), ^(void){

                [self broadcastFoundObject:uuid];

                CBLDocument* aDoc2 = [_database documentWithID:uuid];
                NSDictionary* dict2 = aDoc.properties;
                NSLog(@"aDoc = %@", aDoc2);
                NSLog(@"dict = %@", dict2);
            });

        }
    }

    if(changedTheMissingObjectList)
    {
        [self updateQueryForMissingObjects];
    }
}
// By the way, while we are stopped at checkMissingObjectQuery, thread #33 "CouchbaseLite" shows this stack:
#0  0x3bceea8c in mach_msg_trap ()
#1  0x3bcee88c in mach_msg ()
#2  0x311b87ba in __CFRunLoopServiceMachPort ()
#3  0x311b6ee0 in __CFRunLoopRun ()
#4  0x31121cd6 in CFRunLoopRunSpecific ()
#5  0x31121aba in CFRunLoopRunInMode ()
#6  0x31aee90a in -[NSRunLoop(NSRunLoop) runMode:beforeDate:] ()
#7  0x009b2ad4 in -[CBL_Server runServerThread] at .../external-libs/cbl/Source/CBL_Server.m:116
#8  0x31bb1326 in __NSThread__main__ ()
#9  0x3bd69c1c in _pthread_body ()
#10 0x3bd69b8e in _pthread_start ()
@snej
couchbase member

Something's wrong here. If the document isn't loadable for two seconds after the query returns, then the query isn't actually reporting that document. In your code you're looking at the key of the query row and comparing it to the UUID you want. But is the map function actually emitting the docID of the document as the key? Could you show me what your view definition looks like?

@tgogolin

In case its not clear, I don't know that its not available for 2 seconds. What I know is that attempting it inline inside the observeValueForKeyPath callback fails. And delaying the execution for 0 seconds also fails. And that delaying the execution for 2 seconds succeeds. It might be the case that some shorter delay would work, but I have not experimented; in fact I intentionally chose such a long delay to be more confident that it would work.

We're not making a custom view, just using the canned query returned by [aDataBase queryAllDocuments]

-(void) updateQueryForMissingObjects
{
    if(self.missingObjects.count == 0)
    {
        // No missing objects, destroy the live query if it exists
        if(self.observedLiveQueryForMissingObjects)
        {
            [self.observedLiveQueryForMissingObjects removeObserver:self forKeyPath:@"rows"];
            self.observedLiveQueryForMissingObjects = nil;
        }
    }
    else
    {
        // There are missing objects, create the live query if it doesn't exist
        if(!self.observedLiveQueryForMissingObjects)
        {
            CBLQuery* query = [_database queryAllDocuments];
            self.observedLiveQueryForMissingObjects = [query asLiveQuery];
            [self.observedLiveQueryForMissingObjects addObserver:self forKeyPath:@"rows" options:0 context:NULL];
        }

        // TODO: Verify that is is safe to modify a liveQuery's 'keys' property.
        // If not, we may need to destroy the query and create another one everytime our list of missing objects changes

        // Update the query with the actual objects we are looking for      
        // 'missingObjects' is an NSMutableSet of uuid strings
        self.observedLiveQueryForMissingObjects.keys = [self.missingObjects allObjects];        
    }
}
@snej
couchbase member

// TODO: Verify that is is safe to modify a liveQuery's 'keys' property.

What this will will do is affect the query the next time it triggers, i.e. the next time anything changes in the database. It's not going to cause the query to run immediately. And there's a race condition where, if the database just changed and the query is in the middle of running but hasn't finished yet, your changed key won't apply to that run (and the query still won't run again until there's another change.)

In other words, I don't think this is going to work entirely correctly for you.

If you're waiting for a specific document to show up, you can just instantiate a CBLDocument object with its ID, then observe its kCBLDocumentChangeNotification.

@tgogolin

I may have several documents I'm "waiting" for, but I think it might be manageable to do what you suggest: instantiate the CBLDocument objects and observe them for changes, and un-observe a given doc after I get a change for that document. Thanks, I'll give that a try.

But I still think its kind of a "hole" in the API that if I instantiate a CBLDocument inside the LiveQuery callback that tells me it exists, it may return a nil properties dictionary.

@snej snej was assigned
@jessliu

Hi @tgogolin we have not been able to reproduce, can you see if this is still happening?

@snej snej closed this
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Something went wrong with that request. Please try again.