Uploaded image for project: 'Couchbase Gateway'
  1. Couchbase Gateway
  2. CBG-1663

Gocbv2 CCCP poller after PUT /{db}/ for an invalid bucket never stops

    XMLWordPrintable

Details

    • Bug
    • Resolution: Fixed
    • Major
    • 3.0
    • 3.0
    • SyncGateway
    • Security Level: Public
    • None
    • CBG Sprint 81, CBG Sprint 82
    • 3

    Description

      The gocb retry loop/CCCP polller never stops trying to open a bucket after attemping to create a database with an invalid bucket name.

      Repro:

      1. Start up SG in persistent mode, no buckets/databases
      2. Attempt to create a database with a bucket name that does not exist
      3. See create database request fail as expected:

        2021-08-31T13:23:44.718+01:00 [INF] HTTP:  #011: PUT /beers/ (as ADMIN)
        2021-08-31T13:23:44.718+01:00 [DBG] gocb+: SDK Version: gocbcore/v10.0.1
        2021-08-31T13:23:44.718+01:00 [DBG] gocb+: Creating new agent: &{BucketName:beers UserAgent:gocb/v2.3.0 SeedConfig:{HTTPAddrs:[localhost:8091] MemdAddrs:[localhost:11210]} SecurityConfig:{UseTLS:false TLSRootCAProvider:0x460e380 Auth:0xc000115010 AuthMechanisms:[]} CompressionConfig:{Enabled:false DisableDecompression:false MinSize:0 MinRatio:0} ConfigPollerConfig:{HTTPRedialPeriod:0s HTTPRetryDelay:0s HTTPMaxWait:0s CccpMaxWait:0s CccpPollPeriod:0s} IoConfig:{NetworkType: UseMutationTokens:true UseDurations:true UseOutOfOrderResponses:true DisableXErrorHello:false DisableJSONHello:false DisableSyncReplicationHello:false EnablePITRHello:false UseCollections:true} KVConfig:{ConnectTimeout:10s PoolSize:0 MaxQueueSize:0} HTTPConfig:{MaxIdleConns:0 MaxIdleConnsPerHost:0 IdleConnectionTimeout:0s} DefaultRetryStrategy:0xc000114e60 CircuitBreakerConfig:{Enabled:true VolumeThreshold:0 ErrorThresholdPercentage:0 SleepWindow:0s RollingWindow:0s CompletionCallback:<nil> CanaryTimeout:0s} OrphanReporterConfig:{Enabled:true ReportInterval:0s SampleSize:0} TracerConfig:{Tracer:0xc000114e80 NoRootTraceSpans:true} MeterConfig:{Meter:<nil>}}
        2021-08-31T13:23:44.719+01:00 [DBG] gocb+: CCCP Looper starting.
        2021-08-31T13:23:44.739+01:00 [WRN] gocb: Pipeline Client 0xc0003d5340 failed to bootstrap: authentication failure | {"status_code":36,"document_key":"beers","bucket":"beers","error_name":"EACCESS","error_description":"Not authorized for command","opaque":6,"last_dispatched_to":"localhost:11210","last_dispatched_from":"[::1]:65098","last_connection_id":"1129cab0d551f53f/ee68a8a7bee7891b"} -- base.GoCBCoreLogger.Log() at logger_external.go:79
        2021-08-31T13:23:47.719+01:00 [WRN] gocb: CCCPPOLL: Failed to retrieve CCCP config. authentication failure | {"status_code":36,"document_key":"beers","bucket":"beers","error_name":"EACCESS","error_description":"Not authorized for command","opaque":6,"last_dispatched_to":"localhost:11210","last_dispatched_from":"[::1]:65098","last_connection_id":"1129cab0d551f53f/ee68a8a7bee7891b"} -- base.GoCBCoreLogger.Log() at logger_external.go:79
        2021-08-31T13:23:47.719+01:00 [WRN] gocb: CCCPPOLL: Failed to retrieve config from any node. -- base.GoCBCoreLogger.Log() at logger_external.go:79
        2021-08-31T13:23:49.747+01:00 [WRN] gocb: Pipeline Client 0xc0003d5340 failed to bootstrap: authentication failure | {"status_code":36,"document_key":"beers","bucket":"beers","error_name":"EACCESS","error_description":"Not authorized for command","opaque":6,"last_dispatched_to":"localhost:11210","last_dispatched_from":"[::1]:65102","last_connection_id":"1129cab0d551f53f/f47b48ec0f91b5c6"} -- base.GoCBCoreLogger.Log() at logger_external.go:79
        2021-08-31T13:23:51.638+01:00 [DBG] Config+: Fetching configs from buckets in cluster for group "default"
        2021-08-31T13:23:53.226+01:00 [WRN] gocb: CCCPPOLL: Failed to retrieve CCCP config. authentication failure | {"status_code":36,"document_key":"beers","bucket":"beers","error_name":"EACCESS","error_description":"Not authorized for command","opaque":6,"last_dispatched_to":"localhost:11210","last_dispatched_from":"[::1]:65102","last_connection_id":"1129cab0d551f53f/f47b48ec0f91b5c6"} -- base.GoCBCoreLogger.Log() at logger_external.go:79
        2021-08-31T13:23:53.227+01:00 [WRN] gocb: CCCPPOLL: Failed to retrieve config from any node. -- base.GoCBCoreLogger.Log() at logger_external.go:79
        2021-08-31T13:23:54.719+01:00 [ERR] #011: 500 couldn't save database config: unambiguous timeout | {"InnerError":{"InnerError":{"InnerError":{},"Message":"unambiguous timeout"}},"OperationID":"WaitUntilReady","Opaque":"","TimeObserved":10000240938,"RetryReasons":["NOT_READY","CONNECTION_ERROR"],"RetryAttempts":28,"LastDispatchedTo":"","LastDispatchedFrom":"","LastConnectionID":""} -- rest.(*handler).writeError() at handler.go:954
        2021-08-31T13:23:54.719+01:00 [INF] HTTP: #011:     --> 500 couldn't save database config: unambiguous timeout | {"InnerError":{"InnerError":{"InnerError":{},"Message":"unambiguous timeout"}},"OperationID":"WaitUntilReady","Opaque":"","TimeObserved":10000240938,"RetryReasons":["NOT_READY","CONNECTION_ERROR"],"RetryAttempts":28,"LastDispatchedTo":"","LastDispatchedFrom":"","LastConnectionID":""}  (10000.8 ms)
        

      4. After request has finished, observe below gocb CCCPOLL logs still trying to open the invalid bucket with no way of stopping it:

        2021-08-31T13:26:32.906+01:00 [WRN] gocb: CCCPPOLL: Failed to retrieve CCCP config. authentication failure | {"status_code":36,"document_key":"beers","bucket":"beers","error_name":"EACCESS","error_description":"Not authorized for command","opaque":6,"last_dispatched_to":"localhost:11210","last_dispatched_from":"[::1]:65363","last_connection_id":"1129cab0d551f53f/aef064e4ae6ed423"} -- base.GoCBCoreLogger.Log() at logger_external.go:79
        2021-08-31T13:26:32.906+01:00 [WRN] gocb: CCCPPOLL: Failed to retrieve config from any node. -- base.GoCBCoreLogger.Log() at logger_external.go:79
        2021-08-31T13:26:35.233+01:00 [WRN] gocb: Pipeline Client 0xc0003d5340 failed to bootstrap: authentication failure | {"status_code":36,"document_key":"beers","bucket":"beers","error_name":"EACCESS","error_description":"Not authorized for command","opaque":6,"last_dispatched_to":"localhost:11210","last_dispatched_from":"[::1]:65367","last_connection_id":"1129cab0d551f53f/281cc0d33e466744"} -- base.GoCBCoreLogger.Log() at logger_external.go:79
        2021-08-31T13:26:38.413+01:00 [WRN] gocb: CCCPPOLL: Failed to retrieve CCCP config. authentication failure | {"status_code":36,"document_key":"beers","bucket":"beers","error_name":"EACCESS","error_description":"Not authorized for command","opaque":6,"last_dispatched_to":"localhost:11210","last_dispatched_from":"[::1]:65367","last_connection_id":"1129cab0d551f53f/281cc0d33e466744"} -- base.GoCBCoreLogger.Log() at logger_external.go:79
        2021-08-31T13:26:38.413+01:00 [WRN] gocb: CCCPPOLL: Failed to retrieve config from any node. -- base.GoCBCoreLogger.Log() at logger_external.go:79
        2021-08-31T13:26:40.245+01:00 [WRN] gocb: Pipeline Client 0xc0003d5340 failed to bootstrap: authentication failure | {"status_code":36,"document_key":"beers","bucket":"beers","error_name":"EACCESS","error_description":"Not authorized for command","opaque":6,"last_dispatched_to":"localhost:11210","last_dispatched_from":"[::1]:65372","last_connection_id":"1129cab0d551f53f/6a1be6e6891b60cf"} -- base.GoCBCoreLogger.Log() at logger_external.go:79
        

      Attachments

        Issue Links

          No reviews matched the request. Check your Options in the drop-down menu of this sections header.

          Activity

            People

              jacques.rascagneres Jacques Rascagneres
              ben.brooks Ben Brooks
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Gerrit Reviews

                  There are no open Gerrit changes

                  PagerDuty