Uploaded image for project: 'Couchbase C client library libcouchbase'
  1. Couchbase C client library libcouchbase
  2. CCBC-1521

Bucket-less bootstrap times out when client certificate authentication is being used

    XMLWordPrintable

Details

    • 1

    Description

      Using the same certs I was able to connect using gocb and connect to the rest apis using the python requests library

      lcb_INSTANCE *instance;
      		 
      lcb_CREATEOPTS *createopts;
      		 
      std::string connstr = "couchbases://172.23.111.135?truststorepath=/Users/jakerawsthorne/Code/cbsdk/cbdyncluster/ca.pem&ssl=on&certpath=/Users/jakerawsthorne/Code/cbsdk/cbdyncluster/client.pem&keypath=/Users/jakerawsthorne/Code/cbsdk/cbdyncluster/client.key";
      		 
      lcb_createopts_create(&createopts, LCB_TYPE_CLUSTER);
      		 
      lcb_createopts_connstr(createopts, connstr.c_str(), connstr.size());
      		 
      ASSERT_STATUS_EQ(LCB_SUCCESS, lcb_create(&instance, createopts));
      		 
      ASSERT_STATUS_EQ(LCB_SUCCESS, lcb_connect(instance));
      		 
      ASSERT_STATUS_EQ(LCB_SUCCESS, lcb_wait(instance, LCB_WAIT_DEFAULT));
      		 
      lcb_createopts_destroy(createopts);
      		 
      lcb_destroy(instance);


      0ms [I19f1a190caf88188] {95063/307} [INFO] (instance - L:521) Version=3.2.2, Changeset=fadbd4d1617df952457abfa9984d095015f1ca52
      		 
      0ms [I19f1a190caf88188] {95063/307} [INFO] (instance - L:522) Effective connection string: couchbases://172.23.111.135?console_log_level=5&truststorepath=/Users/jakerawsthorne/Code/cbsdk/cbdyncluster/ca.pem&ssl=on&certpath=/Users/jakerawsthorne/Code/cbsdk/cbdyncluster/client.pem&keypath=/Users/jakerawsthorne/Code/cbsdk/cbdyncluster/client.key. Bucket=(null)
      		 
      2ms [I19f1a190caf88188] {95063/307} [DEBUG] (SSL - L:356) Load verify locations from "/Users/jakerawsthorne/Code/cbsdk/cbdyncluster/ca.pem"
      		 
      3ms [I19f1a190caf88188] {95063/307} [DEBUG] (SSL - L:362) Authenticate with key "/Users/jakerawsthorne/Code/cbsdk/cbdyncluster/client.key", cert "/Users/jakerawsthorne/Code/cbsdk/cbdyncluster/client.pem"
      		 
      908ms [I19f1a190caf88188] {95063/307} [INFO] (instance - L:212) DNS SRV lookup failed: LCB_ERR_UNKNOWN_HOST (1049). Ignore this if not relying on DNS SRV records
      		 
      908ms [I19f1a190caf88188] {95063/307} [DEBUG] (instance - L:155) Adding host 172.23.111.135:18091 to initial HTTP bootstrap list
      		 
      908ms [I19f1a190caf88188] {95063/307} [DEBUG] (instance - L:155) Adding host 172.23.111.135:11207 to initial CCCP bootstrap list
      		 
      908ms [I19f1a190caf88188] {95063/307} [TRACE] (instance - L:193) Bootstrap hosts loaded (cccp:1, http:1)
      		 
      908ms [I19f1a190caf88188] {95063/307} [INFO] (bootstrap - L:277) Requested network configuration: heuristic
      		 
      908ms [I19f1a190caf88188] {95063/307} [DEBUG] (confmon - L:94) Preparing providers (this may be called multiple times)
      		 
      908ms [I19f1a190caf88188] {95063/307} [DEBUG] (confmon - L:100) Provider CCCP is ENABLED
      		 
      908ms [I19f1a190caf88188] {95063/307} [DEBUG] (confmon - L:100) Provider HTTP is ENABLED
      		 
      908ms [I19f1a190caf88188] {95063/307} [TRACE] (confmon - L:319) Refreshing current cluster map (bucket: (null))
      		 
      908ms [I19f1a190caf88188] {95063/307} [INFO] (cccp - L:176) Requesting connection to node 172.23.111.135:11207 for CCCP configuration
      		 
      908ms [I19f1a190caf88188] {95063/307} [DEBUG] (lcbio_mgr - L:501) <172.23.111.135:11207> (HE=0x7fc5af0090f0) Creating new connection because none are available in the pool
      		 
      908ms [I19f1a190caf88188] {95063/307} [TRACE] (lcbio_mgr - L:413) <172.23.111.135:11207> (HE=0x7fc5af0090f0) New pool entry: I=0x7fc5af0099e0
      		 
      908ms [I19f1a190caf88188] {95063/307} [INFO] (connection - L:497) <172.23.111.135:11207> (SOCK=7aabc0edef3b9791) Starting. Timeout=2000000us
      		 
      908ms [I19f1a190caf88188] {95063/307} [DEBUG] (connection - L:262) <172.23.111.135:11207> (SOCK=7aabc0edef3b9791) Created new socket with FD=11
      		 
      908ms [I19f1a190caf88188] {95063/307} [TRACE] (connection - L:362) <172.23.111.135:11207> (SOCK=7aabc0edef3b9791) Scheduling I/O watcher for asynchronous connection completion.
      		 
      908ms [I19f1a190caf88188] {95063/307} [TRACE] (confmon - L:305) Attempting to retrieve cluster map via CCCP
      		 
      1061ms [I19f1a190caf88188] {95063/307} [INFO] (connection - L:159) <172.23.111.135:11207> (SOCK=7aabc0edef3b9791) Connected established
      		 
      1061ms [I19f1a190caf88188] {95063/307} [DEBUG] (connection - L:106) <172.23.111.135:11207> (SOCK=7aabc0edef3b9791) Successfully set TCP_NODELAY
      		 
      1061ms [I19f1a190caf88188] {95063/307} [DEBUG] (connection - L:106) <172.23.111.135:11207> (SOCK=7aabc0edef3b9791) Successfully set TCP_KEEPALIVE
      		 
      1061ms [I19f1a190caf88188] {95063/307} [DEBUG] (lcbio_mgr - L:369) <172.23.111.135:11207> (HE=0x7fc5af0090f0) Received result for I=0x7fc5af0099e0,C=0x0; E=0x0
      		 
      1061ms [I19f1a190caf88188] {95063/307} [DEBUG] (lcbio_mgr - L:329) <172.23.111.135:11207> (HE=0x7fc5af0090f0) Assigning R=0x7fc5af0098e0 SOCKET=0x7fc5af009c20
      		 
      1061ms [I19f1a190caf88188] {95063/307} [DEBUG] (ioctx - L:94) <172.23.111.135:11207> (CTX=0x7fc5ad706c80,unknown) Pairing with SOCK=7aabc0edef3b9791
      		 
      1062ms [I19f1a190caf88188] {95063/307} [DEBUG] (negotiation - L:469) <172.23.111.135:11207> (CTX=0x7fc5ad706c80,sasl,SASLREQ=0x7fc5ae808200) HELO identificator: {"a":"libcouchbase/3.2.2 (Darwin-19.6.0; x86_64; AppleClang 12.0.0.12000032)","i":"19f1a190caf88188/7aabc0edef3b9791"}, features: 0x02 (TLS), 0x06 (XATTR), 0x0b (JSON), 0x08 (Select bucket), 0x07 (XERROR), 0x03 (TCP nodelay), 0x0a (Snappy), 0x04 (Mutation seqno), 0x0f (Tracing), 0x12 (Collections), 0x0e (Unordered execution), 0x17 (Create as Deleted), 0x14 (Preserve Expiry)
      		 
      1062ms [I19f1a190caf88188] {95063/307} [TRACE] (SSL - L:242) sock=0x7fc5af009c20: ST(0x10). before SSL initialization. R(0x1)U
      		 
      1225ms [I19f1a190caf88188] {95063/307} [TRACE] (SSL - L:242) sock=0x7fc5af009c20: ST(0x20). SSL negotiation finished successfully. R(0x1)U
      		 
      1225ms [I19f1a190caf88188] {95063/307} [DEBUG] (SSL - L:246) sock=0x7fc5af009c20. Using SSL version TLSv1.3. Cipher=TLS_AES_256_GCM_SHA384
      		 
      1382ms [I19f1a190caf88188] {95063/307} [DEBUG] (negotiation - L:500) <172.23.111.135:11207> (CTX=0x7fc5ad706c80,sasl,SASLREQ=0x7fc5ae808200) Server supports features: 0x03 (TCP nodelay), 0x04 (Mutation seqno), 0x06 (XATTR), 0x07 (XERROR), 0x08 (Select bucket), 0x0a (Snappy), 0x0b (JSON), 0x0e (Unordered execution), 0x0f (Tracing), 0x12 (Collections), 0x14 (Preserve Expiry), 0x17 (Create as Deleted)
      		 
      1382ms [I19f1a190caf88188] {95063/307} [DEBUG] (ioctx - L:139) <172.23.111.135:11207> (CTX=0x7fc5ad706c80,sasl) Destroying context. Pending Writes=0, Entered=true, Socket Refcount=1
      		 
      1382ms [I19f1a190caf88188] {95063/307} [DEBUG] (ioctx - L:94) <172.23.111.135:11207> (CTX=0x7fc5ad419e90,unknown) Pairing with SOCK=7aabc0edef3b9791
      		 
      3386ms [I19f1a190caf88188] {95063/307} [ERROR] (cccp - L:187) <172.23.111.135:11207> (CTX=0x7fc5ad419e90,bc_cccp) Could not get configuration: LCB_ERR_TIMEOUT (201)
      		 
      3386ms [I19f1a190caf88188] {95063/307} [DEBUG] (ioctx - L:139) <172.23.111.135:11207> (CTX=0x7fc5ad419e90,bc_cccp) Destroying context. Pending Writes=0, Entered=false, Socket Refcount=1
      		 
      3386ms [I19f1a190caf88188] {95063/307} [INFO] (confmon - L:216) Provider 'CCCP' failed: LCB_ERR_TIMEOUT (201)
      		 
      3386ms [I19f1a190caf88188] {95063/307} [DEBUG] (confmon - L:260) Will try next provider in 0us
      		 
      3386ms [I19f1a190caf88188] {95063/307} [TRACE] (confmon - L:305) Attempting to retrieve cluster map via HTTP
      		 
      3386ms [I19f1a190caf88188] {95063/307} [TRACE] (htconfig - L:359) Starting HTTP Configuration Provider 0x7fc5ad506700
      		 
      3386ms [I19f1a190caf88188] {95063/307} [INFO] (connection - L:497) <172.23.111.135:18091> (SOCK=5b79083f31e71754) Starting. Timeout=2000000us
      		 
      3386ms [I19f1a190caf88188] {95063/307} [DEBUG] (connection - L:262) <172.23.111.135:18091> (SOCK=5b79083f31e71754) Created new socket with FD=11
      		 
      3386ms [I19f1a190caf88188] {95063/307} [TRACE] (connection - L:362) <172.23.111.135:18091> (SOCK=5b79083f31e71754) Scheduling I/O watcher for asynchronous connection completion.
      		 
      3537ms [I19f1a190caf88188] {95063/307} [INFO] (connection - L:159) <172.23.111.135:18091> (SOCK=5b79083f31e71754) Connected established
      		 
      3537ms [I19f1a190caf88188] {95063/307} [DEBUG] (connection - L:106) <172.23.111.135:18091> (SOCK=5b79083f31e71754) Successfully set TCP_NODELAY
      		 
      3537ms [I19f1a190caf88188] {95063/307} [DEBUG] (connection - L:106) <172.23.111.135:18091> (SOCK=5b79083f31e71754) Successfully set TCP_KEEPALIVE
      		 
      3537ms [I19f1a190caf88188] {95063/307} [DEBUG] (htconfig - L:315) Successfuly connected to REST API 172.23.111.135:18091
      		 
      3537ms [I19f1a190caf88188] {95063/307} [DEBUG] (ioctx - L:94) <172.23.111.135:18091> (CTX=0x7fc5ad706ce0,unknown) Pairing with SOCK=5b79083f31e71754
      		 
      3537ms [I19f1a190caf88188] {95063/307} [TRACE] (SSL - L:242) sock=0x7fc5af009d00: ST(0x10). before SSL initialization. R(0x1)U
      		 
      3883ms [I19f1a190caf88188] {95063/307} [TRACE] (SSL - L:242) sock=0x7fc5af009d00: ST(0x20). SSL negotiation finished successfully. R(0x1)U
      		 
      3883ms [I19f1a190caf88188] {95063/307} [DEBUG] (SSL - L:246) sock=0x7fc5af009d00. Using SSL version TLSv1.2. Cipher=DHE-RSA-AES256-SHA
      		 
      4045ms [I19f1a190caf88188] {95063/307} [TRACE] (htconfig - L:214) <172.23.111.135:18091> (CTX=0x7fc5ad706ce0,bc_http) Received 395 bytes on HTTP stream
      		 
      4071ms [I19f1a190caf88188] {95063/307} [TRACE] (htconfig - L:214) <172.23.111.135:18091> (CTX=0x7fc5ad706ce0,bc_http) Received 7536 bytes on HTTP stream
      		 
      5909ms [I19f1a190caf88188] {95063/307} [ERROR] (bootstrap - L:205) Failed to bootstrap client=0x7fc5ad505c60. Error=LCB_ERR_TIMEOUT (201) (Last=LCB_ERR_TIMEOUT (201)), Message="Failed to bootstrap in time"

       

      Attachments

        For Gerrit Dashboard: CCBC-1521
        # Subject Branch Project Status CR V
        166047,3 CCBC-1509: record more info in TLS log callback master libcouchbase Status: MERGED +2 +1
        166078,3 CCBC-1521: fix bootstrap process when client cert is used master libcouchbase Status: MERGED +2 +1
        167208,2 CCBC-1521: fix bootstrap process when client cert is used and error map is supported master libcouchbase Status: MERGED +2 +1

        Activity

          People

            avsej Sergey Avseyev
            jake.rawsthorne#1 Jake Rawsthorne [X] (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Gerrit Reviews

                There are no open Gerrit changes

                PagerDuty