Hi Michael,
Initial check for “doc exist” works fine then couple of upsert , get and remove occurs. And when tries to do the “doc exist” check second time for another doc it fails.
I am using camel async routes in application and which internally tries to interact with couchbase using reactive api.
getBucket().defaultCollection().reactive().exists(documentId)
.subscribe(new Consumer() {
The same in sync mode works fine.
getBucket().defaultCollection().exists(documentId).exists();
Following are the logs. Check all “AsyncProcessor:155” statements.
18-Jun-2020 11:12:58.669| INFO|ID-MUM-LAP-624-1592478369652-0-386:SaveForLaterCouchbaseRouteBuilderDoesGraphExist|core:493 [com.couchbase.core][DnsSrvLookupFailedEvent][446ms] DNS SRV lookup failed (name not found), trying to bootstrap from given hostname directly.
18-Jun-2020 11:12:59.778| INFO|ID-MUM-LAP-624-1592478369652-0-386:SaveForLaterCouchbaseRouteBuilderDoesGraphExist|core:493 [com.couchbase.core][CoreCreatedEvent] {“clientVersion”:“3.0.5”,“clientGitHash”:“ac204fc7”,“coreVersion”:“2.0.6”,“coreGitHash”:“ac204fc7”,“userAgent”:“couchbase-java/3.0.5 (Windows 10 10.0 amd64; OpenJDK 64-Bit Server VM 11.0.6+10)”,“maxNumRequestsInRetry”:32768,“ioEnvironment”:{“nativeIoEnabled”:true,“eventLoopThreadCount”:2,“eventLoopGroups”:[“NioEventLoopGroup”]},“ioConfig”:{“captureTraffic”:,“mutationTokensEnabled”:true,“networkResolution”:“auto”,“dnsSrvEnabled”:true,“tcpKeepAlivesEnabled”:true,“tcpKeepAliveTimeMs”:60000,“configPollIntervalMs”:2500,“kvCircuitBreakerConfig”:“disabled”,“queryCircuitBreakerConfig”:“disabled”,“viewCircuitBreakerConfig”:“disabled”,“searchCircuitBreakerConfig”:“disabled”,“analyticsCircuitBreakerConfig”:“disabled”,“managerCircuitBreakerConfig”:“disabled”,“numKvConnections”:1,“maxHttpConnections”:12,“idleHttpConnectionTimeoutMs”:30000,“configIdleRedialTimeoutMs”:300000},“compressionConfig”:{“enabled”:true,“minRatio”:0.83,“minSize”:32},“securityConfig”:{“tlsEnabled”:false,“nativeTlsEnabled”:true,“hasTrustCertificates”:false,“trustManagerFactory”:null},“timeoutConfig”:{“kvMs”:150000000,“kvDurableMs”:10000,“managementMs”:75000,“queryMs”:300000000,“viewMs”:75000000,“searchMs”:75000,“analyticsMs”:75000,“connectMs”:60000000,“disconnectMs”:30000000},“loggerConfig”:{“customLogger”:null,“fallbackToConsole”:false,“disableSlf4j”:false,“loggerName”:“CouchbaseLogger”,“diagnosticContextEnabled”:false},“orphanReporterConfig”:{“emitIntervalMs”:10000,“sampleSize”:10,“queueLength”:1024},“retryStrategy”:“BestEffortRetryStrategy”,“requestTracer”:“OwnedSupplier”} {“coreId”:“0x3de68bb000000001”,“seedNodes”:[{“address”:“localhost”}]}
18-Jun-2020 11:12:59.787| INFO|ID-MUM-LAP-624-1592478369652-0-386:SaveForLaterCouchbaseRouteBuilderDoesGraphExist|node:493 [com.couchbase.node][NodeConnectedEvent] Node connected {“coreId”:“0x3de68bb000000001”,“managerPort”:“8091”,“remote”:“localhost”}
18-Jun-2020 11:13:00.494|DEBUG|ID-MUM-LAP-624-1592478369652-0-386:SaveForLaterCouchbaseRouteBuilderDoesGraphExist|DocumentExistsAsyncProcessor:155 About to attempt to check if document exists (async:true)
18-Jun-2020 11:13:00.494|DEBUG|ID-MUM-LAP-624-1592478369652-0-386:SaveForLaterCouchbaseRouteBuilderDoesGraphExist|DocumentExistsAsyncProcessor:155 Document id /s4l/GemCase/-1/s4lAggregatedGraph
18-Jun-2020 11:13:01.245| INFO|ID-MUM-LAP-624-1592478369652-0-386:SaveForLaterCouchbaseRouteBuilderDoesGraphExist|core:493 [com.couchbase.core][BucketOpenedEvent][760ms] Opened bucket “bsTransactionsLocks” {“coreId”:“0x3de68bb000000001”}
18-Jun-2020 11:13:01.772|DEBUG|ID-MUM-LAP-624-1592478369652-0-386:DataConsolidationRoute_DC|DocumentProductionContext:155 ppRequest before DocProd
…
…
…
18-Jun-2020 11:13:20.944| INFO|ID-MUM-LAP-624-1592478369652-0-386:CreateCaseServiceRoute_SUBMIT_GRAPH|CreateCaseWorkflowContextBean:231 Returning allocated business key’ 20/WS/16350/20’
18-Jun-2020 11:13:20.946| INFO|ID-MUM-LAP-624-1592478369652-0-386:AutoGenerationDocumentRoute|AutoGenerationDocumentRoute:159 No Document failure
18-Jun-2020 11:13:20.947|DEBUG|ID-MUM-LAP-624-1592478369652-0-386:CouchbaseCacheRouteBuilderRemoveTx|RemoveDocumentAsyncProcessor:155 About to attempt to remove document (async:true)
18-Jun-2020 11:13:20.948|DEBUG|ID-MUM-LAP-624-1592478369652-0-386:CouchbaseCacheRouteBuilderRemoveTx|RemoveDocumentAsyncProcessor:155 Document id transaction-179ae0cf329c1c08f137aa07217f8c06ae267487cb3962611f94cc3db0883918
18-Jun-2020 11:13:20.982|DEBUG|ID-MUM-LAP-624-1592478369652-0-386:CouchbaseCacheRouteBuilderRemoveTx|RemoveDocumentAsyncProcessor:155 Async Document remove errored com.couchbase.client.core.error.DocumentNotFoundException: Document with the given id not found {“completed”:true,“coreId”:“0x3de68bb000000001”,“idempotent”:false,“lastChannelId”:“3DE68BB000000001/000000002D83212A”,“lastDispatchedFrom”:“127.0.0.1:51680”,“lastDispatchedTo”:“localhost:11210”,“requestId”:11,“requestType”:“RemoveRequest”,“retried”:0,“service”:{“bucket”:“bsTransactionsLocks”,“collection”:"_default",“documentId”:“transaction-179ae0cf329c1c08f137aa07217f8c06ae267487cb3962611f94cc3db0883918”,“opaque”:“0x15”,“scope”:"_default",“syncDurability”:{“empty”:true,“present”:false},“type”:“kv”},“status”:“NOT_FOUND”,“timeoutMs”:10000,“timings”:{“dispatchMicros”:664,“totalMicros”:26730}}
18-Jun-2020 11:13:20.983|DEBUG|ID-MUM-LAP-624-1592478369652-0-386:CreateCaseServiceRoute_POST_APPLIED_LOGIC|CreateCaseServiceRoute:155 Inside post Applied Logic: com.northgateis.pole.schema.PutPoleObjectsResponseDto@e76a7c5
…
…
…
…
…
18-Jun-2020 11:14:01.068|DEBUG|ID-MUM-LAP-624-1592478369652-0-668:CouchbaseCacheRouteBuilderAddTx|UpsertDocumentAsyncProcessor:155 About to attempt to upsert document (async:true)
18-Jun-2020 11:14:01.076|DEBUG|ID-MUM-LAP-624-1592478369652-0-668:CouchbaseCacheRouteBuilderAddTx|UpsertDocumentAsyncProcessor:155 {“gpoRequests”:["{"_type":“com.northgateis.pole.schema.GetPoleObjectsRequestDto”,“header”:{“passwordHash”:“88316137-956f-434c-a5f3-d6c282a1467c”,“clientName”:"…[A BIG JSON OF 26KB size]…“lockingType”:“DEEP”}
18-Jun-2020 11:14:01.329|DEBUG|ID-MUM-LAP-624-1592478369652-0-386:SaveForLaterCouchbaseRouteBuilderDoesGraphExist|UpsertDocumentAsyncProcessor:155 Async Document upserted transaction-7ba0957bf263ae8e372a94d0db2a30d13555ae6542829af5db1c0bffb2e32ebf
18-Jun-2020 11:14:01.330|DEBUG|ID-MUM-LAP-624-1592478369652-0-668:LockingContextAcquireLocksRoute|IsLockRequired:155 Lock is required
18-Jun-2020 11:14:01.330| INFO|ID-MUM-LAP-624-1592478369652-0-668:LockingContextAcquireLocksRoute_ACQUIRE_LOCK|LockingContextAcquireLockProxyBean:231 Requesting Lock for Entities [GemCase 360005]
18-Jun-2020 11:14:01.330|DEBUG|ID-MUM-LAP-624-1592478369652-0-668:LockingContextAcquireLocksRoute_ACQUIRE_LOCK|LockingContext:155 Get acquire locks request called
18-Jun-2020 11:14:01.331|DEBUG|ID-MUM-LAP-624-1592478369652-0-668:LockingContextAcquireLocksRoute_ACQUIRE_LOCK|LockingContext:155 Dont error on failure to acquire lock
18-Jun-2020 11:14:01.331|DEBUG|ID-MUM-LAP-624-1592478369652-0-668:LockingContextAcquireLocksRoute_ACQUIRE_LOCK|LockingContextAcquireLockProxyBean:155
18-Jun-2020 11:14:01.332|DEBUG|ID-MUM-LAP-624-1592478369652-0-668:PoleWebServiceStubRoute|PoleWebServiceStubRoute:155 Sending to cxf:bean:toPoleService
18-Jun-2020 11:14:01.632|DEBUG|ID-MUM-LAP-624-1592478369652-0-668:LockingContextAcquireLocksRoute_ACQUIRE_LOCK|LockingContextAcquireLockProxyBean:155
18-Jun-2020 11:14:01.632| INFO|ID-MUM-LAP-624-1592478369652-0-668:LockingContextAcquireLocksRoute_ACQUIRE_LOCK|LockingContextAcquireLockProxyBean:231 Lock successfully acquired for Entities [GemCase 360005]
18-Jun-2020 11:14:01.633|DEBUG|ID-MUM-LAP-624-1592478369652-0-668:LockingContextAcquireLocksRoute_ACQUIRE_LOCK|LockingContext:155 Set lock acquired called
18-Jun-2020 11:14:01.633|DEBUG|ID-MUM-LAP-624-1592478369652-0-668:LockingContextAcquireLocksRoute_ACQUIRE_LOCK|LockingContext:155 Lock acquired
18-Jun-2020 11:14:01.637|DEBUG|ID-MUM-LAP-624-1592478369652-0-668:CouchbaseCacheRouteBuilderAddDeepLock|UpsertDocumentAsyncProcessor:155 About to attempt to upsert document (async:true)
18-Jun-2020 11:14:01.639|DEBUG|ID-MUM-LAP-624-1592478369652-0-668:CouchbaseCacheRouteBuilderAddDeepLock|UpsertDocumentAsyncProcessor:155 {“gpoRequests”:["{"_type":“com.northgateis.pole.schema.GetPoleObjectsRequestDto”,“header”:{“passwordHash”:“88316137-956f-434c-a5f3-d6c282a1467c”,“clientName”:"…[A BIG JSON OF 26KB size]…“lockingType”:“DEEP”}
18-Jun-2020 11:14:01.758|DEBUG|:|UpsertDocumentAsyncProcessor:155 Async Document upserted transaction-7ba0957bf263ae8e372a94d0db2a30d13555ae6542829af5db1c0bffb2e32ebf
18-Jun-2020 11:14:01.760|DEBUG|ID-MUM-LAP-624-1592478369652-0-668:CouchbaseCacheRouteBuilderAddDeepLock|UpsertDocumentAsyncProcessor:155 About to attempt to upsert document (async:true)
18-Jun-2020 11:14:01.761|DEBUG|ID-MUM-LAP-624-1592478369652-0-668:CouchbaseCacheRouteBuilderAddDeepLock|UpsertDocumentAsyncProcessor:155 {“transactionId”:“7ba0957bf263ae8e372a94d0db2a30d13555ae6542829af5db1c0bffb2e32ebf”,“entityKey”:"{“objectRef”:360005,“entityType”:“GemCase”}"}
18-Jun-2020 11:14:01.845|DEBUG|:|UpsertDocumentAsyncProcessor:155 Async Document upserted entityTransaction-{“objectRef”:360005,“entityType”:“GemCase”}
18-Jun-2020 11:14:01.856|DEBUG|ID-MUM-LAP-624-1592478369652-0-668:SaveForLaterCouchbaseRouteBuilderDoesGraphExist|DocumentExistsAsyncProcessor:155 About to attempt to check if document exists (async:true)
18-Jun-2020 11:14:01.856|DEBUG|ID-MUM-LAP-624-1592478369652-0-668:SaveForLaterCouchbaseRouteBuilderDoesGraphExist|DocumentExistsAsyncProcessor:155 Document id /s4l/GemCase/360005/s4lAggregatedGraph
18-Jun-2020 11:14:04.482| INFO|ID-MUM-LAP-624-1592478369652-0-386:SaveForLaterCouchbaseRouteBuilderDoesGraphExist|config:493 [com.couchbase.config][BucketConfigRefreshFailedEvent] Reason: INDIVIDUAL_REQUEST_FAILED, Type: KV, Cause: com.couchbase.client.core.error.UnambiguousTimeoutException: CarrierBucketConfigRequest {“cancelled”:true,“completed”:true,“coreId”:“0x3de68bb000000001”,“idempotent”:true,“lastChannelId”:“3DE68BB000000001/000000002D83212A”,“lastDispatchedFrom”:“127.0.0.1:51680”,“lastDispatchedTo”:“localhost:11210”,“reason”:“TIMEOUT”,“requestId”:69,“requestType”:“CarrierBucketConfigRequest”,“retried”:0,“service”:{“bucket”:“bsTransactionsLocks”,“collection”:"_default",“opaque”:“0x4f”,“scope”:"_default",“target”:“localhost”,“type”:“kv”},“timeoutMs”:2500} {“coreId”:“0x3de68bb000000001”}
…
… same error keeps printing