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

LCB does not time out ops when lcb_open still in progress

    XMLWordPrintable

Details

    • Bug
    • Status: Open
    • Major
    • Resolution: Unresolved
    • 3.0.2
    • 3.2.6
    • tools
    • None
    • 1

    Description

      I've noticed that when calling lcb_open against a bucket which does not exist, lcb is trying to connect (which is fine of course), but for some reason it seems to not time out ops that are scheduled in the meantime.

      Consider the code in https://github.com/couchbaselabs/couchbase-rs/blob/master/couchbase/examples/kv.rs#L14, but instead of opening "travel-sample", just choose a name which does not exist. The following logs show what LCB is doing in this case:

          Blocking waiting for file lock on build directory
         Compiling couchbase-sys v1.0.0-alpha.4 (/Users/michaelnitschinger/couchbase/code/rust/couchbase-rs/couchbase-sys)
         Compiling couchbase v1.0.0-alpha.4 (/Users/michaelnitschinger/couchbase/code/rust/couchbase-rs/couchbase)
          Finished dev [unoptimized + debuginfo] target(s) in 33.74s
           Running `target/debug/examples/kv`
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb] Using libcouchbase IO transport
      [2020-07-16T12:39:02Z INFO  couchbase::io::lcb::callbacks] Version=0.3.0_163_g1bb1c24783, Changeset=1bb1c247832e774468840bf9cfa667a3b9bd97ae
      [2020-07-16T12:39:02Z INFO  couchbase::io::lcb::callbacks] Effective connection string: couchbase://127.0.0.1. Bucket=(null)
      [2020-07-16T12:39:02Z INFO  couchbase::io::lcb::callbacks] DNS SRV lookup failed: LCB_ERR_UNKNOWN_HOST (1049). Ignore this if not relying on DNS SRV records
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] Adding host 127.0.0.1:8091 to initial HTTP bootstrap list
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] Adding host 127.0.0.1:11210 to initial CCCP bootstrap list
      [2020-07-16T12:39:02Z INFO  couchbase::io::lcb::callbacks] Requested network configuration: heuristic
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] Preparing providers (this may be called multiple times)
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] Provider CCCP is ENABLED
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] Provider HTTP is ENABLED
      [2020-07-16T12:39:02Z INFO  couchbase::io::lcb::callbacks] Requesting connection to node 127.0.0.1:11210 for CCCP configuration
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] <127.0.0.1:11210> (HE=0x7f9015d052c0) Creating new connection because none are available in the pool
      [2020-07-16T12:39:02Z INFO  couchbase::io::lcb::callbacks] <127.0.0.1:11210> (SOCK=fb42ab7724540ac0) Starting. Timeout=2000000us
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] <127.0.0.1:11210> (SOCK=fb42ab7724540ac0) Created new socket with FD=4
      [2020-07-16T12:39:02Z INFO  couchbase::io::lcb::callbacks] <127.0.0.1:11210> (SOCK=fb42ab7724540ac0) Connected established
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] <127.0.0.1:11210> (SOCK=fb42ab7724540ac0) Successfully set TCP_NODELAY
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] <127.0.0.1:11210> (SOCK=fb42ab7724540ac0) Successfully set TCP_KEEPALIVE
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] <127.0.0.1:11210> (HE=0x7f9015d052c0) Received result for I=0x7f9015d043c0,C=0x0; E=0x0
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] <127.0.0.1:11210> (HE=0x7f9015d052c0) Assigning R=0x7f9015d05400 SOCKET=0x7f9015d056e0
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] <127.0.0.1:11210> (CTX=0x7f9015c06dc0,unknown) Pairing with SOCK=fb42ab7724540ac0
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] <127.0.0.1:11210> (CTX=0x7f9015c06dc0,sasl,SASLREQ=0x7f9015c06b50) HELO identificator: {"a":"libcouchbase/0.3.0_163_g1bb1c24783 (Darwin-19.4.0; x86_64; Clang 11.0.3.11030032)","i":"7e679f657d216d0b/fb42ab7724540ac0"}, features: 0x02 (TLS), 0x06 (XATTR), 0x0b (JSON), 0x08 (Select bucket), 0x07 (XERROR), 0x03 (TCP nodelay), 0x0a (Snappy), 0x04 (Mutation seqno), 0x0f (Tracing), 0x12 (Collections)
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] <127.0.0.1:11210> (CTX=0x7f9015c06dc0,sasl,SASLREQ=0x7f9015c06b50) Server supports features: 0x03 (TCP nodelay), 0x04 (Mutation seqno), 0x06 (XATTR), 0x07 (XERROR), 0x08 (Select bucket), 0x0a (Snappy), 0x0b (JSON), 0x0f (Tracing)
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] <127.0.0.1:11210> (CTX=0x7f9015c06dc0,sasl) Destroying context. Pending Writes=0, Entered=true, Socket Refcount=1
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] <127.0.0.1:11210> (CTX=0x7f9015c06fb0,unknown) Pairing with SOCK=fb42ab7724540ac0
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] <127.0.0.1:11210> (CTX=0x7f9015c06fb0,bc_cccp) Destroying context. Pending Writes=0, Entered=true, Socket Refcount=1
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] <127.0.0.1:11210> (HE=0x7f9015d052c0) Placing socket back into the pool. I=0x7f9015d043c0,C=0x7f9015d056e0
      [2020-07-16T12:39:02Z INFO  couchbase::io::lcb::callbacks] Setting new configuration. Received via CCCP
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] Preparing providers (this may be called multiple times)
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] Provider CCCP is ENABLED
      [2020-07-16T12:39:02Z INFO  couchbase::io::lcb::callbacks] Selected network configuration: "default"
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::instance] Starting bucket bind for foobar
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] Preparing providers (this may be called multiple times)
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] Provider CCCP is ENABLED
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] <127.0.0.1:11210> (HE=0x7f9015d052c0) Found ready connection in pool. Reusing socket and not creating new connection
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] <127.0.0.1:11210> (HE=0x7f9015d052c0) Assigning R=0x7f9015e06d10 SOCKET=0x7f9015d056e0
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::callbacks] <127.0.0.1:11210> (CTX=0x7f9015e06e10,unknown) Pairing with SOCK=fb42ab7724540ac0
      [2020-07-16T12:39:02Z DEBUG couchbase::io::lcb::instance] Finished bucket bind for foobar
      [2020-07-16T12:39:02Z ERROR couchbase::io::lcb::callbacks] <NOHOST:NOPORT> (CTX=0x0,) Could not get configuration: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:02Z INFO  couchbase::io::lcb::callbacks] Provider 'CCCP' failed: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:02Z WARN  couchbase::io::lcb::callbacks] Received authentication error during bootstrap
      [2020-07-16T12:39:04Z ERROR couchbase::io::lcb::callbacks] <NOHOST:NOPORT> (CTX=0x0,) Could not get configuration: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:04Z INFO  couchbase::io::lcb::callbacks] Provider 'CCCP' failed: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:04Z WARN  couchbase::io::lcb::callbacks] Received authentication error during bootstrap
      [2020-07-16T12:39:07Z ERROR couchbase::io::lcb::callbacks] <NOHOST:NOPORT> (CTX=0x0,) Could not get configuration: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:07Z INFO  couchbase::io::lcb::callbacks] Provider 'CCCP' failed: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:07Z WARN  couchbase::io::lcb::callbacks] Received authentication error during bootstrap
      [2020-07-16T12:39:07Z ERROR couchbase::io::lcb::callbacks] Failed to bootstrap client=0x7f9015d04450. Error=LCB_ERR_TIMEOUT (201) (Last=LCB_ERR_AUTHENTICATION_FAILURE (206)), Message=Failed to bootstrap in time
      [2020-07-16T12:39:07Z DEBUG couchbase::io::lcb::callbacks] Libcouchbase notified of completed bucket open attempt for bucket Some("foobar") (status: 0xc9)
      [2020-07-16T12:39:09Z ERROR couchbase::io::lcb::callbacks] <NOHOST:NOPORT> (CTX=0x0,) Could not get configuration: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:09Z INFO  couchbase::io::lcb::callbacks] Provider 'CCCP' failed: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:09Z WARN  couchbase::io::lcb::callbacks] Received authentication error during bootstrap
      [2020-07-16T12:39:12Z ERROR couchbase::io::lcb::callbacks] <NOHOST:NOPORT> (CTX=0x0,) Could not get configuration: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:12Z INFO  couchbase::io::lcb::callbacks] Provider 'CCCP' failed: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:12Z WARN  couchbase::io::lcb::callbacks] Received authentication error during bootstrap
      [2020-07-16T12:39:14Z ERROR couchbase::io::lcb::callbacks] <NOHOST:NOPORT> (CTX=0x0,) Could not get configuration: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:14Z INFO  couchbase::io::lcb::callbacks] Provider 'CCCP' failed: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:14Z WARN  couchbase::io::lcb::callbacks] Received authentication error during bootstrap
      [2020-07-16T12:39:17Z ERROR couchbase::io::lcb::callbacks] <NOHOST:NOPORT> (CTX=0x0,) Could not get configuration: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:17Z INFO  couchbase::io::lcb::callbacks] Provider 'CCCP' failed: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:17Z WARN  couchbase::io::lcb::callbacks] Received authentication error during bootstrap
      [2020-07-16T12:39:19Z ERROR couchbase::io::lcb::callbacks] <NOHOST:NOPORT> (CTX=0x0,) Could not get configuration: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:19Z INFO  couchbase::io::lcb::callbacks] Provider 'CCCP' failed: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:19Z WARN  couchbase::io::lcb::callbacks] Received authentication error during bootstrap
      [2020-07-16T12:39:22Z ERROR couchbase::io::lcb::callbacks] <NOHOST:NOPORT> (CTX=0x0,) Could not get configuration: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:22Z INFO  couchbase::io::lcb::callbacks] Provider 'CCCP' failed: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:22Z WARN  couchbase::io::lcb::callbacks] Received authentication error during bootstrap
      [2020-07-16T12:39:24Z ERROR couchbase::io::lcb::callbacks] <NOHOST:NOPORT> (CTX=0x0,) Could not get configuration: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:24Z INFO  couchbase::io::lcb::callbacks] Provider 'CCCP' failed: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:24Z WARN  couchbase::io::lcb::callbacks] Received authentication error during bootstrap
      [2020-07-16T12:39:27Z ERROR couchbase::io::lcb::callbacks] <NOHOST:NOPORT> (CTX=0x0,) Could not get configuration: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:27Z INFO  couchbase::io::lcb::callbacks] Provider 'CCCP' failed: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:27Z WARN  couchbase::io::lcb::callbacks] Received authentication error during bootstrap
      [2020-07-16T12:39:29Z ERROR couchbase::io::lcb::callbacks] <NOHOST:NOPORT> (CTX=0x0,) Could not get configuration: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:29Z INFO  couchbase::io::lcb::callbacks] Provider 'CCCP' failed: LCB_ERR_AUTHENTICATION_FAILURE (206)
      [2020-07-16T12:39:29Z WARN  couchbase::io::lcb::callbacks] Received authentication error during bootstrap
      .....
      

      Attachments

        Issue Links

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

          Activity

            Relatedly, it seems that the same behaviour is exhibited to lcb_connect as well. Specifically if you specify an incorrect host with a long kv_connect_timeout, the operation does not fail until bootstrapping fails (which actually doesn't seem to adhere to kv_connect_timeout either).

            brett19 Brett Lawson added a comment - Relatedly, it seems that the same behaviour is exhibited to lcb_connect as well. Specifically if you specify an incorrect host with a long kv_connect_timeout, the operation does not fail until bootstrapping fails (which actually doesn't seem to adhere to kv_connect_timeout either).

            People

              avsej Sergey Avseyev
              daschl Michael Nitschinger
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

                Created:
                Updated:

                Gerrit Reviews

                  There are no open Gerrit changes

                  PagerDuty