CredStore error on iOS


#1

I’m getting a keychain/credentail store related error log with a cookie-based replication to a sync gateway behind an SSL proxy. The replication comes thru fine, but just wondering if any one knows root cause.

I only see this on a pull replication and not push. Any one else seen this?

CredStore - performQuery - Error copying matching creds. Error=-25300, query={
class = inet;
“m_Limit” = “m_LimitAll”;
ptcl = htps;
“r_Attributes” = 1;
srvr = “****.com”;
sync = syna;
}

iOS 11
sync gateway/sdk 1.4


#2

This seems to be a problem trying to access the credentials from the keychain. Looking up the error code -25300 here , it corresponds to errSecItemNotFound which as name indicates implies that item isn’t found in keychain (https://developer.apple.com/documentation/security/errsecitemnotfound)

Would suggest that you dump the contents of the keychain and verify if you are getting any errors when trying to write credentials to the keychain.


#3

I am also getting the same error as mliu, when running the sample code from the iOS CouchbaseList setup documentation.

XCode 9, iOS 11, CBlite 1.4, CBgateway 1.5. Running from Simulator pointing to a local instance of sync_gateway.

https://developer.couchbase.com/documentation/mobile/1.4/installation/ios/index.html

Can you explain how couchbase interacts with the device KeyChain under the hood?

Is the issue that CBLite is trying to write credentials to the KeyChain but receives the “errSecItemNotFound”?
Do you have any suggestions on how to dump the contents of the KeyChain?

Logs with “SyncVerbose” enabled:

13:05:06.889| Couchbase Lite using SQLite version 3.19.3 (2017-06-27 16:48:08 2b0954060fe10d6de6d479287dd88890f1bef6cc1beca11bc6cdb79f72e2377b)
13:05:06.892| SQLite message: recovered 94 frames from WAL file /Users/andrew/Library/Developer/CoreSimulator/Devices/BC24806C-4FD1-4FCA-A1D4-AEC9733DA68B/data/Containers/Data/Application/C659EDC9-C7DF-4F8F-AE45-0945D02CC8D3/Library/Application Support/CouchbaseLite/app.cblite2/db.sqlite3-wal
Document ID :: -rws4A3BRci6p8bpNJ1226u
Learning iOS
13:05:06.916| Sync: CBLReplication[to http://localhost:4984/hello]: offline, progress = 0 / 0, err: (null)
13:05:06.916| Sync: CBLReplication[from http://localhost:4984/hello]: offline, progress = 0 / 0, err: (null)
13:05:06.918‖ Sync: CBLRestPusher[http://localhost:4984/hello] STARTING ...
2017-10-30 13:05:06.919626-0600 CouchBaseExample[29749:3630211] CredStore - performQuery - Error copying matching creds.  Error=-25300, query={
    atyp = http;
    class = inet;
    "m_Limit" = "m_LimitAll";
    ptcl = http;
    "r_Attributes" = 1;
    srvr = localhost;
    sync = syna;
}
13:05:06.926‖ Sync: CBLRestPusher[http://localhost:4984/hello]: Reachability state = <localhost>:reachable (02), suspended=0
13:05:06.930‖ Sync: CBLRestPusher[http://localhost:4984/hello]: Going online
13:05:06.931‖ Sync: CBLRestPusher[http://localhost:4984/hello]: No local checkpoint; not getting remote one
13:05:06.931‖ Sync: CBLRestPusher[http://localhost:4984/hello]: Received 8 revs
13:05:06.931‖ Sync: CBLRestPusher[http://localhost:4984/hello] Progress: set active = 1
13:05:06.931‖ Sync: CBLRestPusher[http://localhost:4984/hello]: postProgressChanged (0/0, active=1 (batch=8, net=0), lastSeq=(null), online=1, error=(null))
13:05:06.931‖ Sync: *** CBLRestPusher[http://localhost:4984/hello]: BEGIN processInbox (8 sequences)
13:05:06.932‖ Sync: <CBLRemoteSession: 0x60000008edd0>: POST /hello/_revs_diff
13:05:06.933‖ Sync: *** CBLRestPusher[http://localhost:4984/hello]: END processInbox (lastSequence=(null))
13:05:06.933‖ Sync: CBLRestPusher[http://localhost:4984/hello]: postProgressChanged (0/0, active=1 (batch=0, net=1), lastSeq=(null), online=1, error=(null))
13:05:06.933| Sync: CBLReplication[to http://localhost:4984/hello]: active, progress = 0 / 0, err: (null)
13:05:06.933‖ Sync: CBLRestPuller[http://localhost:4984/hello] STARTING ...
2017-10-30 13:05:06.945017-0600 CouchBaseExample[29749:3630211] CredStore - performQuery - Error copying matching creds.  Error=-25300, query={
    atyp = http;
    class = inet;
    "m_Limit" = "m_LimitAll";
    ptcl = http;
    "r_Attributes" = 1;
    srvr = localhost;
    sync = syna;
}
13:05:06.946‖ Sync: CBLRestPuller[http://localhost:4984/hello]: Reachability state = <localhost>:reachable (02), suspended=0
13:05:06.947‖ Sync: CBLRestPuller[http://localhost:4984/hello]: Going online
13:05:06.947‖ Sync: CBLRestPuller[http://localhost:4984/hello]: No local checkpoint; not getting remote one
13:05:06.947‖ Sync: CBLRestPuller[http://localhost:4984/hello] Progress: set active = 1
13:05:06.947‖ Sync: CBLRestPuller[http://localhost:4984/hello]: postProgressChanged (0/0, active=1 (batch=0, net=1), lastSeq=(null), online=1, error=(null))
13:05:06.947‖ Sync: CBLRestPuller[http://localhost:4984/hello] starting ChangeTracker: mode=0, since=(null)
13:05:06.948‖ Sync: CBLSocketChangeTracker[0x6040001a0ee0 hello]: POST //localhost:4984/hello/_changes?feed=normal&heartbeat=300000&style=all_docs
2017-10-30 13:05:06.969079-0600 CouchBaseExample[29749:3630177] CredStore - performQuery - Error copying matching creds.  Error=-25300, query={
    atyp = http;
    class = inet;
    "m_Limit" = "m_LimitAll";
    ptcl = http;
    "r_Attributes" = 1;
    sdmn = "Couchbase Sync Gateway";
    srvr = localhost;
    sync = syna;
}
13:05:07.038‖ Sync: CBLRestPuller[http://localhost:4984/hello]: postProgressChanged (0/0, active=1 (batch=0, net=1), lastSeq=(null), online=1, error=(null))
13:05:07.038| Sync: CBLReplication[from http://localhost:4984/hello]: active, progress = 0 / 0, err: (null)
2017-10-30 13:05:07.040957-0600 CouchBaseExample[29749:3630211] CredStore - performQuery - Error copying matching creds.  Error=-25300, query={
    atyp = http;
    class = inet;
    "m_Limit" = "m_LimitAll";
    ptcl = http;
    "r_Attributes" = 1;
    sdmn = "Couchbase Sync Gateway";
    srvr = localhost;
    sync = syna;
}
13:05:07.051‖ Sync: CBLRestPusher[http://localhost:4984/hello]: Server is Couchbase Sync Gateway/1.5.0
2017-10-30 13:05:07.056132-0600 CouchBaseExample[29749:3630211] CredStore - performQuery - Error copying matching creds.  Error=-25300, query={
    atyp = http;
    class = inet;
    "m_Limit" = "m_LimitAll";
    ptcl = http;
    "r_Attributes" = 1;
    sdmn = "Couchbase Sync Gateway";
    srvr = localhost;
    sync = syna;
}
13:05:07.056‖ <BLIPHTTPLogic: 0x60400008f550>: HTTP auth failed; sent Authorization: (null)  ;  got WWW-Authenticate: Basic realm="Couchbase Sync Gateway"
13:05:07.057‖ CBLSocketChangeTracker[0x6040001a0ee0 hello]: Can't connect, giving up: CBLHTTP[401, <http://localhost:4984/hello/_changes?feed=normal&heartbeat=300000&style=all_docs>]<--NSURLError[-1013, <http://localhost:4984/hello/_changes?feed=normal&heartbeat=300000&style=all_docs>]
13:05:07.057‖ Sync: CBLRestPuller[http://localhost:4984/hello]: ChangeTracker stopped; error=CBLHTTP[401, <http://localhost:4984/hello/_changes?feed=normal&heartbeat=300000&style=all_docs>]<--NSURLError[-1013, <http://localhost:4984/hello/_changes?feed=normal&heartbeat=300000&style=all_docs>]
13:05:07.079‖ Sync: CBLRestPuller[http://localhost:4984/hello] Progress: set error = CBLHTTP[401, <http://localhost:4984/hello/_changes?feed=normal&heartbeat=300000&style=all_docs>]<--NSURLError[-1013, <http://localhost:4984/hello/_changes?feed=normal&heartbeat=300000&style=all_docs>]
13:05:07.079‖ Sync: CBLRestPuller[http://localhost:4984/hello] STOPPING...
13:05:07.079‖ Sync: CBLRestPuller[http://localhost:4984/hello] Progress: set active = 0
13:05:07.079‖ Sync: CBLRestPuller[http://localhost:4984/hello]: postProgressChanged (0/0, active=0 (batch=0, net=0), lastSeq=(null), online=1, error=CBLHTTP[401, <http://localhost:4984/hello/_changes?feed=normal&heartbeat=300000&style=all_docs>]<--NSURLError[-1013, <http://localhost:4984/hello/_changes?feed=normal&heartbeat=300000&style=all_docs>])
13:05:07.079‖ Sync: CBLRestPuller[http://localhost:4984/hello] STOPPED
13:05:07.079‖ Replication: CBLRestPuller[http://localhost:4984/hello] took 0.134 sec; error=CBLHTTP[401, <http://localhost:4984/hello/_changes?feed=normal&heartbeat=300000&style=all_docs>]<--NSURLError[-1013, <http://localhost:4984/hello/_changes?feed=normal&heartbeat=300000&style=all_docs>]
13:05:07.085| Sync: CBLReplication[from http://localhost:4984/hello]: stopped, progress = 0 / 0, err: CBLHTTP[401, <http://localhost:4984/hello/_changes?feed=normal&heartbeat=300000&style=all_docs>]<--NSURLError[-1013, <http://localhost:4984/hello/_changes?feed=normal&heartbeat=300000&style=all_docs>]
13:05:07.085‖ CBLRemoteJSONRequest[POST http://localhost:4984/hello/_revs_diff]: Got error CBLHTTP[401, "Login required", <http://localhost:4984/hello/_revs_diff>]
13:05:07.085‖ Sync: CBLRestPusher[http://localhost:4984/hello] Progress: set error = CBLHTTP[401, "Login required", <http://localhost:4984/hello/_revs_diff>]
13:05:07.085‖ Sync: CBLRestPusher[http://localhost:4984/hello] STOPPING...
13:05:07.085‖ Sync: CBLRestPusher[http://localhost:4984/hello] Progress: set active = 0
13:05:07.085‖ Sync: CBLRestPusher[http://localhost:4984/hello]: postProgressChanged (0/0, active=0 (batch=0, net=0), lastSeq=(null), online=1, error=CBLHTTP[401, "Login required", <http://localhost:4984/hello/_revs_diff>])
13:05:07.104‖ Sync: CBLRestPusher[http://localhost:4984/hello] STOPPED
13:05:07.105‖ Replication: CBLRestPusher[http://localhost:4984/hello] took 0.182 sec; error=CBLHTTP[401, "Login required", <http://localhost:4984/hello/_revs_diff>]
13:05:07.105| Sync: CBLReplication[to http://localhost:4984/hello]: stopped, progress = 0 / 0, err: CBLHTTP[401, "Login required", <http://localhost:4984/hello/_revs_diff>]

Thanks,

Andrew


#4

FYI I’ve seen something similar to this with Xamarin. It originally stemmed from an iOS 10 simulator bug, but perhaps something similar is going on? I could fix it by deleting the app from the device and reinstalling.


#5

I am running into the identical problem (same as what @andrew.mclean shown above, even though I am using CBL1.3.1 and SyncGateway 1.3.1) . I am wondering what is a viable solution to fix this? I assume we can’t dump the contents of the keychain in a real app, right? I reinstalled app but it does not solve the problem.

The link provided by @borrrden says " The fix would involve only checking for tokens once ever, and returning early after that combined with setting the username from the sync gateway session." But since I don’t know the business logic that CBLite interact with iOS keyChain, I don’t know how to implement this suggestion for an app meant to be used by general public. Can someone elaborate the solution to this problem please? Adding in some sample code would be great. Thanks!

FYI, I did enabled the GUEST access to SyncGateway, i.e. in sync_gateway.json,under my database, I have following:

  "users": {
    "GUEST": {"disabled": false, "admin_channels": ["*"] }
  }

#6

That CredStore - performQuery… warning is not something we’re logging. It comes from Apple, not Couchbase Lite, so we don’t know exactly what it means; CredStore isn’t even something that appears in the Keychain API, so I assume it’s an internal class.

If you can reproduce this [I don’t think we’ve ever seen it here], you could try to find the backtrace of where it gets called, by setting a breakpoint at CFLog.


#7

Ah, I googled for “CredStore performQuery” and found this helpful StackOverflow thread . Best answer appears to be

This error occurs when trying to retrieve an URLCredential from URLCredentialStorage for an unknown URLProtectionSpace

In other words, it’s a byproduct of the URL loading system checking whether there is a saved password in the Keychain. That implies it’s a harmless red herring and the real problem you’re having is elsewhere.

It’s also worth noting that CBL 1.3.1 is probably EOL at this point and you should really consider upgrading to at least 1.4.1 if not 2.1.1.


#8

Thanks for the answers, Jens.

The problem I have is the iOS app is only able to do push replication, pull replication doesn’t happen at all. I asked this CredStore thing because I thought this was the cause (as this CredStore error always shows up before I should see some result of pull replication printed to the Xcode console.). I found that stackoverflow thread too, I followed the suggestion in the best answer, but did not solve the problem.

If you are sure CredStore is not the cause of pull replication problem, could you give some suggestion on how to debug this problem? CBL of my iOS app is set up following the Couchbase Connect 2017’s Couchbase Mobile tutorial (the link to it that used to work: https://github.com/couchbaselabs/mobile-training-todo/blob/master/ios/Todo). view/livequery and push/pull replications are all identical to the example code given, nothing added/subtracted/modified.
FYI, when the app make GET and POST requests to other servers, everything works fine and no CredStore error showed up.

Regarding version of CBL, the iOS app started off with 1.4.1, encountered this pull replication problem accompanied by this CredStore error, thinking maybe 1.4.1 is doing something fancy behind the scene during pull replication, so I downgraded to CBL1.3.1, which is the version I used for Android version of this app (never had any replication problem, by the way), only to find out 1.3.1 has the identical problem accompanied by the identical error… Anyway, the plan is to stick to CBL 1.3.1 for current release of the app (as there’s no time and appetite to learn how things work in later versions and re-write the code), but will surely try CBL 2.x in next release.


#9

If the replicator can push, then there’s nothing wrong at the socket or auth layers, so the CredStore thing is a red herring.

The first thing to do in diagnosing replicator problems is always to turn on verbose logging. IIRC, in 1.x you’d run the app (in Xcode) with args -LogSyncVerbose YES. Or you can turn on Sync logging from the API.

Also, are you sure the docs being pulled aren’t conflicting with local changes? That can make it appear that they aren’t being pulled.