Python, Node SDK Query_timeout Setting

Couchbase Server
, ,
1

Both Python and Node SDKs are set to Cluster query_detry = 10s and 120s, but they do not work.
If not set, it runs for up to 75 seconds and ends with ‘UnabundantTimeoutException’.
‘curl-v-u administrator:password
I checked with http://localhost:8091/Settings/querySettings’ and found it set to 0.
I set query_timeout in sql++ and it works.

The ‘cluster timeout option’ is not working. Is there a solution?

example1: Not running
options = ClusterTimeoutOptions(kv_timeout=timedelta(seconds=60), query_timeout=timedelta(seconds=10)) cluster = Cluster(host, ClusterOptions( PasswordAuthenticator(username, pw), timeout_options=options))

example2 : running
const query = q_opts = QueryOptions(timeout=timedelta(seconds=10)) query_iter = cluster.query("SELECT * FROMtravel-sampleLIMIT 10000", q_opts) count = 0 for r in query_iter.rows(): count += 1 print(f"Got {count} rows")

Reference : Timeout on N1QL DELETE query - Python SDK - Couchbase Forums

SDK versions are both up to date.

2

If you make it easy to reproduce by including a complete sample, I’ll check it.

3

Hi @bellpumpkin – I think debug level logs will give more insight to what options the SDK is passing to the server for a query request (python: PYCBC_LOG_LEVEL=debug python <your_test_script>.py, node.js: CBPPLOGLEVEL=debug node <yourTestScript>.js). The SDK will not set the timeout on the server but sets the timeout value for each request.

I do not think there should be a problem w/ the Node.js SDK, could you provide logs?

There is a problem w/ the Python SDK, so I created PYCBC-1521. Unfortunately the only work-around in the interim is to set the timeout per request via the QueryOptions (or kwargs).

1 Like
4

node log :

[2023-09-12 10:10:45.058] [9852,38532] [debug] 58ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/b55d88d6-280a-49cf-c979-5cbcd4894622/plain/-] <192.168.10.142:11210> attempt to establish MCBP connection
[2023-09-12 10:10:45.060] [9852,5592] [debug] 2ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/b55d88d6-280a-49cf-c979-5cbcd4894622/plain/-] <192.168.10.142:11210> connecting to 192.168.10.142:11210, timeout=2000ms
[2023-09-12 10:10:45.063] [9852,5592] [debug] 2ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/b55d88d6-280a-49cf-c979-5cbcd4894622/plain/-] <192.168.10.142:11210> connected to 192.168.10.142:11210
[2023-09-12 10:10:45.066] [9852,5592] [debug] 3ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/b55d88d6-280a-49cf-c979-5cbcd4894622/plain/-] <192.168.10.142/192.168.10.142:11210> user_agent={"a":"cxx/1.0.0/9fc39ce;couchnode%2F4.2.0%20(node%2F18.12.1%3B%20v8%2F10.2.154.15-node.12%3B%20ssl%2F3.0.7%2Bquic)","i":"83a63c1e-499b-4ab4-ab91-52a2d6f7012f/b55d88d6-280a-49cf-c979-5cbcd4894622"}, requested_features=[tcp_nodelay, mutation_seqno, xattr, xerror, select_bucket, json, duplex, alt_request_support, tracing, sync_replication, vattr, collections, subdoc_create_as_deleted, preserve_ttl, unordered_execution, snappy]
[2023-09-12 10:10:45.069] [9852,5592] [debug] 3ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/b55d88d6-280a-49cf-c979-5cbcd4894622/plain/-] <192.168.10.142/192.168.10.142:11210> supported_features=[tcp_nodelay, mutation_seqno, xattr, xerror, select_bucket, snappy, json, duplex, unordered_execution, tracing, alt_request_support, sync_replication, collections, preserve_ttl, vattr, subdoc_create_as_deleted]
[2023-09-12 10:10:45.086] [9852,5592] [debug] 16ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/b55d88d6-280a-49cf-c979-5cbcd4894622/plain/-] <192.168.10.142/192.168.10.142:11210> received new configuration: #<config:76f8f4e5-f1dc-48ba-4552-679da27cccfa rev=1:90632, nodes(7)=[#<node:0 hostname="192.168.10.131", plain=(kv=11210, mgmt=8091, capi=8092), tls=(kv=11207, mgmt=18091, capi=18092), alt=[]>, #<node:1 hostname="192.168.10.135", plain=(kv=11210, mgmt=8091, capi=8092), tls=(kv=11207, mgmt=18091, capi=18092), alt=[]>, #<node:2 hostname="192.168.10.137", plain=(kv=11210, mgmt=8091, capi=8092), tls=(kv=11207, mgmt=18091, capi=18092), alt=[]>, #<node:3 hostname="192.168.10.138", plain=(kv=11210, mgmt=8091, capi=8092), tls=(kv=11207, mgmt=18091, capi=18092), alt=[]>, #<node:4 hostname="192.168.10.139", plain=(kv=11210, mgmt=8091, capi=8092), tls=(kv=11207, mgmt=18091, capi=18092), alt=[]>, #<node:5 hostname="192.168.10.140", plain=(mgmt=8091, cbas=8095, fts=8094, n1ql=8093), tls=(mgmt=18091, cbas=18095, fts=18094, n1ql=18093), alt=[]>, #<node:6 hostname="192.168.10.142", plain=(mgmt=8091, cbas=8095, fts=8094, n1ql=8093), tls=(mgmt=18091, cbas=18095, fts=18094, n1ql=18093), alt=[]>], bucket_caps=[], cluster_caps=[n1ql_enhanced_prepared_statements]>
[2023-09-12 10:10:45.088] [9852,5592] [debug] 1ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/b55d88d6-280a-49cf-c979-5cbcd4894622/plain/-] <192.168.10.142/192.168.10.142:11210> detected network is "default"
[2023-09-12 10:10:45.089] [9852,38532] [debug] 1ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/3c9f9845-5744-4b81-d822-e19097988746/plain/demo] <192.168.10.142:11210> attempt to establish MCBP connection
[2023-09-12 10:10:45.090] [9852,5592] [debug] 1ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/3c9f9845-5744-4b81-d822-e19097988746/plain/demo] <192.168.10.142:11210> connecting to 192.168.10.142:11210, timeout=2000ms
[2023-09-12 10:10:45.093] [9852,5592] [debug] 2ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/cd6d2e1d-599f-44e9-5cfe-81c7286aef13] connecting to 192.168.10.142:8093, timeout=2000ms
[2023-09-12 10:10:45.093] [9852,38532] [debug] 0ms, QUERY: client_context_id="efd0aef8-f4bc-4bed-c238-500ed6d103e7", prep=false, "SELECT META(c).id AS k,{c.custid,c.name,c.phone, c.email, c.birthday} FROM demo.test.customer AS c JOIN demo.test.orders AS i on i.custid = c.custid JOIN demo.test.address AS ad ON c.zipcode = ad.zipcode JOIN demo.test.orders_detail AS od ON od.orderno = i.orderno;"
[2023-09-12 10:10:45.094] [9852,5592] [debug] 1ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/3c9f9845-5744-4b81-d822-e19097988746/plain/demo] <192.168.10.142:11210> connected to 192.168.10.142:11210
[2023-09-12 10:10:45.095] [9852,5592] [debug] 1ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/3c9f9845-5744-4b81-d822-e19097988746/plain/demo] <192.168.10.142/192.168.10.142:11210> user_agent={"a":"cxx/1.0.0/9fc39ce;couchnode%2F4.2.0%20(node%2F18.12.1%3B%20v8%2F10.2.154.15-node.12%3B%20ssl%2F3.0.7%2Bquic)","i":"83a63c1e-499b-4ab4-ab91-52a2d6f7012f/3c9f9845-5744-4b81-d822-e19097988746"}, requested_features=[tcp_nodelay, mutation_seqno, xattr, xerror, select_bucket, json, duplex, alt_request_support, tracing, sync_replication, vattr, collections, subdoc_create_as_deleted, preserve_ttl, unordered_execution, snappy]
[2023-09-12 10:10:45.096] [9852,5592] [debug] 0ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/cd6d2e1d-599f-44e9-5cfe-81c7286aef13] connected to 192.168.10.142:8093
[2023-09-12 10:10:45.098] [9852,5592] [debug] 1ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/3c9f9845-5744-4b81-d822-e19097988746/plain/demo] <192.168.10.142/192.168.10.142:11210> supported_features=[tcp_nodelay, mutation_seqno, xattr, xerror, select_bucket, snappy, json, duplex, unordered_execution, tracing, alt_request_support, sync_replication, collections, preserve_ttl, vattr, subdoc_create_as_deleted]
[2023-09-12 10:10:45.116] [9852,5592] [debug] 17ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/3c9f9845-5744-4b81-d822-e19097988746/plain/demo] <192.168.10.142/192.168.10.142:11210> kv_engine node does not have configuration propagated yet (opcode=select_bucket (0x89), status=not_found (0x01), opaque=6)
[2023-09-12 10:10:45.117] [9852,5592] [debug] 1ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/3c9f9845-5744-4b81-d822-e19097988746/plain/demo] <192.168.10.137:11210> attempt to establish MCBP connection
[2023-09-12 10:10:45.119] [9852,5592] [debug] 1ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/3c9f9845-5744-4b81-d822-e19097988746/plain/demo] <192.168.10.137:11210> connecting to 192.168.10.137:11210, timeout=2000ms
[2023-09-12 10:10:45.126] [9852,5592] [debug] 7ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/3c9f9845-5744-4b81-d822-e19097988746/plain/demo] <192.168.10.137:11210> connected to 192.168.10.137:11210
[2023-09-12 10:10:45.127] [9852,5592] [debug] 0ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/3c9f9845-5744-4b81-d822-e19097988746/plain/demo] <192.168.10.137/192.168.10.137:11210> user_agent={"a":"cxx/1.0.0/9fc39ce;couchnode%2F4.2.0%20(node%2F18.12.1%3B%20v8%2F10.2.154.15-node.12%3B%20ssl%2F3.0.7%2Bquic)","i":"83a63c1e-499b-4ab4-ab91-52a2d6f7012f/3c9f9845-5744-4b81-d822-e19097988746"}, requested_features=[tcp_nodelay, mutation_seqno, xattr, xerror, select_bucket, json, duplex, alt_request_support, tracing, sync_replication, vattr, collections, subdoc_create_as_deleted, preserve_ttl, unordered_execution, snappy]
[2023-09-12 10:10:55.102] [9852,5592] [warning] 9974ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/3c9f9845-5744-4b81-d822-e19097988746/plain/demo] <192.168.10.137/192.168.10.137:11210> unable to bootstrap in time
[2023-09-12 10:10:55.102] [9852,5592] [warning] 0ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/3c9f9845-5744-4b81-d822-e19097988746/plain/demo] <192.168.10.137/192.168.10.137:11210> failed to bootstrap session ec=unambiguous_timeout (14), bucket="demo"
[2023-09-12 10:10:55.103] [9852,5592] [debug] 0ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/3c9f9845-5744-4b81-d822-e19097988746/plain/demo] <192.168.10.137/192.168.10.137:11210> stop MCBP connection, reason=do_not_retry
[2023-09-12 10:10:55.104] [9852,5592] [debug] 0ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/3c9f9845-5744-4b81-d822-e19097988746/plain/demo] <192.168.10.137/192.168.10.137:11210> destroy MCBP connection
failed to open bucket: [Error: unambiguous_timeout (14)] { code: 14 }
[2023-09-12 10:11:59.673] [9852,5592] [debug] 64569ms, [83a63c1e-499b-4ab4-ab91-52a2d6f7012f/cd6d2e1d-599f-44e9-5cfe-81c7286aef13] <192.168.10.142:8093> put HTTP session back to idle connections
ERR: [UnambiguousTimeoutError: unambiguous timeout] {
  cause: [Error: unambiguous_timeout (14)] {
    ctxtype: 'query',
    code: 14,
    first_error_code: 1080,
    first_error_message: 'Timeout 1m14.5s exceeded',
    client_context_id: 'efd0aef8-f4bc-4bed-c238-500ed6d103e7',
    statement: 'SELECT META(c).id AS k,{c.custid,c.name,c.phone, c.email, c.birthday} FROM demo.test.customer AS c JOIN demo.test.orders AS i on i.custid = c.custid JOIN demo.test.address AS ad ON c.zipcode = ad.zipcode JOIN demo.test.orders_detail AS od ON od.orderno = i.orderno;',
    parameters: '{"client_context_id":"efd0aef8-f4bc-4bed-c238-500ed6d103e7","metrics":false,"statement":"SELECT META(c).id AS k,{c.custid,c.name,c.phone, c.email, c.birthday} FROM demo.test.customer AS c JOIN demo.test.orders AS i on i.custid = c.custid JOIN demo.test.address AS ad ON c.zipcode = ad.zipcode JOIN demo.test.orders_detail AS od ON od.orderno = i.orderno;","timeout":"74500ms"}',
    method: 'POST',
    path: '/query/service',
    http_status: 200,
    http_body: '{\n' +
      '"requestID": "2ffc20a2-8983-4897-b9af-ed3708d14a6a",\n' +
      '"clientContextID": "efd0aef8-f4bc-4bed-c238-500ed6d103e7",\n' +
      '"signature": {"$1":"object","k":"json"},\n' +
      '"results": [\n' +
      '],\n' +
      '"errors": [{"code":1080,"msg":"Timeout 1m14.5s exceeded","retry":true}],\n' +
      '"status": "timeout"\n' +
      '}\n',
    last_dispatched_to: '192.168.10.142:8093',
    last_dispatched_from: '192.168.10.4:13607',
    retry_attempts: 0,
    retry_reasons: []
  },
  context: QueryErrorContext {
    statement: 'SELECT META(c).id AS k,{c.custid,c.name,c.phone, c.email, c.birthday} FROM demo.test.customer AS c JOIN demo.test.orders AS i on i.custid = c.custid JOIN demo.test.address AS ad ON c.zipcode = ad.zipcode JOIN demo.test.orders_detail AS od ON od.orderno = i.orderno;',
    client_context_id: 'efd0aef8-f4bc-4bed-c238-500ed6d103e7',
    parameters: '{"client_context_id":"efd0aef8-f4bc-4bed-c238-500ed6d103e7","metrics":false,"statement":"SELECT META(c).id AS k,{c.custid,c.name,c.phone, c.email, c.birthday} FROM demo.test.customer AS c JOIN demo.test.orders AS i on i.custid = c.custid JOIN demo.test.address AS ad ON c.zipcode = ad.zipcode JOIN demo.test.orders_detail AS od ON od.orderno = i.orderno;","timeout":"74500ms"}',
    http_response_code: 200,
    http_response_body: '{\n' +
      '"requestID": "2ffc20a2-8983-4897-b9af-ed3708d14a6a",\n' +
      '"clientContextID": "efd0aef8-f4bc-4bed-c238-500ed6d103e7",\n' +
      '"signature": {"$1":"object","k":"json"},\n' +
      '"results": [\n' +
      '],\n' +
      '"errors": [{"code":1080,"msg":"Timeout 1m14.5s exceeded","retry":true}],\n' +
      '"status": "timeout"\n' +
      '}\n'
  }
}

node script :

const couchbase = require("couchbase");

async function main() {
  // For a secure cluster connection, use `couchbases://<your-cluster-ip>` instead.
  const clusterConnStr = "couchbase://192.168.10.142,192.168.10.137";
  const username = "Administrator";
  const password = "password";
  const bucketName = "demo";

  const cluster = await couchbase.connect(clusterConnStr, {
    username: username,
    password: password,
    queryTimeout: 5000,
  });

  const bucket = cluster.bucket(bucketName);

  // Get a reference to the default collection, required only for older Couchbase server versions
  const defaultCollection = bucket.defaultCollection();

  const collection = bucket.scope("test").collection("test");

  const query =
    "SELECT META(c).id AS k,{c.custid,c.name,c.phone, c.email, c.birthday} FROM demo.test.customer AS c JOIN demo.test.orders AS i on i.custid = c.custid JOIN demo.test.address AS ad ON c.zipcode = ad.zipcode JOIN demo.test.orders_detail AS od ON od.orderno = i.orderno;";
  let queryResult = await cluster.query(query);

  console.log("Query Results:");
  queryResult.rows.forEach((row) => {
    console.log(row);
  });
}

// Run the main function
main()
  .catch((err) => {
    console.log("ERR:", err);
    process.exit(1);
  })
  .then(process.exit);
5

python log :

[2023-09-12 10:21:54.496] [806432,806432] [debug] 160ms, Using nameserver: 127.0.0.53
[2023-09-12 10:21:54.500] [806432,806432] [debug] 3ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/07c0e1-c025-584f-d48b-dfab28854536df/plain/-] <192.168.10.138:11210> attempt to establish MCBP connection
[2023-09-12 10:21:54.500] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/07c0e1-c025-584f-d48b-dfab28854536df/plain/-] <192.168.10.138:11210> connecting to 192.168.10.138:11210, timeout=50000ms
[2023-09-12 10:21:54.507] [806432,806433] [debug] 6ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/07c0e1-c025-584f-d48b-dfab28854536df/plain/-] <192.168.10.138:11210> connected to 192.168.10.138:11210
[2023-09-12 10:21:54.507] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/07c0e1-c025-584f-d48b-dfab28854536df/plain/-] <192.168.10.138/192.168.10.138:11210> user_agent={"a":"cxx/1.0.0/adc416d;Linux/x86_64;pycbc/4.1.6 (python/3.10.12)","i":"976b47-94fe-1749-ab1a-c5984d33c65ca1/07c0e1-c025-584f-d48b-dfab28854536df"}, requested_features=[tcp_nodelay, xattr, xerror, select_bucket, json, duplex, alt_request_support, tracing, sync_replication, vattr, collections, subdoc_create_as_deleted, preserve_ttl, unordered_execution, mutation_seqno]
[2023-09-12 10:21:54.510] [806432,806433] [debug] 2ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/07c0e1-c025-584f-d48b-dfab28854536df/plain/-] <192.168.10.138/192.168.10.138:11210> supported_features=[tcp_nodelay, mutation_seqno, xattr, xerror, select_bucket, json, duplex, unordered_execution, tracing, alt_request_support, sync_replication, collections, preserve_ttl, vattr, subdoc_create_as_deleted]
[2023-09-12 10:21:54.528] [806432,806433] [debug] 18ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/07c0e1-c025-584f-d48b-dfab28854536df/plain/-] <192.168.10.138/192.168.10.138:11210> detected network is "default"
[2023-09-12 10:21:54.528] [806432,806433] [debug] 0ms, PYCBC: create conn callback completed
[2023-09-12 10:21:54.529] [806432,806432] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/88332a-a45a-7942-e771-6196e6cb000fef/plain/demo] <192.168.10.138:11210> attempt to establish MCBP connection
[2023-09-12 10:21:54.531] [806432,806433] [debug] 1ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/88332a-a45a-7942-e771-6196e6cb000fef/plain/demo] <192.168.10.138:11210> connecting to 192.168.10.138:11210, timeout=50000ms
[2023-09-12 10:21:54.531] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/88332a-a45a-7942-e771-6196e6cb000fef/plain/demo] <192.168.10.138:11210> connected to 192.168.10.138:11210
[2023-09-12 10:21:54.531] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/88332a-a45a-7942-e771-6196e6cb000fef/plain/demo] <192.168.10.138/192.168.10.138:11210> user_agent={"a":"cxx/1.0.0/adc416d;Linux/x86_64;pycbc/4.1.6 (python/3.10.12)","i":"976b47-94fe-1749-ab1a-c5984d33c65ca1/88332a-a45a-7942-e771-6196e6cb000fef"}, requested_features=[tcp_nodelay, xattr, xerror, select_bucket, json, duplex, alt_request_support, tracing, sync_replication, vattr, collections, subdoc_create_as_deleted, preserve_ttl, unordered_execution, mutation_seqno]
[2023-09-12 10:21:54.532] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/88332a-a45a-7942-e771-6196e6cb000fef/plain/demo] <192.168.10.138/192.168.10.138:11210> supported_features=[tcp_nodelay, mutation_seqno, xattr, xerror, select_bucket, json, duplex, unordered_execution, tracing, alt_request_support, sync_replication, collections, preserve_ttl, vattr, subdoc_create_as_deleted]
[2023-09-12 10:21:54.541] [806432,806433] [debug] 9ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/88332a-a45a-7942-e771-6196e6cb000fef/plain/demo] <192.168.10.138/192.168.10.138:11210> selected bucket: demo
[2023-09-12 10:21:54.546] [806432,806433] [debug] 4ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/demo] initialize configuration rev=1:90703
[2023-09-12 10:21:54.548] [806432,806433] [debug] 1ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/demo] rev=1:90703, add session="2ddf94-0923-ce47-a42f-30c81b4528399d", address="192.168.10.131:11210", index=0
[2023-09-12 10:21:54.549] [806432,806433] [debug] 1ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/2ddf94-0923-ce47-a42f-30c81b4528399d/plain/demo] <192.168.10.131:11210> attempt to establish MCBP connection
[2023-09-12 10:21:54.550] [806432,806433] [debug] 1ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/demo] rev=1:90703, add session="a80cab-a1c9-0f4c-695d-26c163d2b61779", address="192.168.10.135:11210", index=1
[2023-09-12 10:21:54.552] [806432,806433] [debug] 1ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/a80cab-a1c9-0f4c-695d-26c163d2b61779/plain/demo] <192.168.10.135:11210> attempt to establish MCBP connection
[2023-09-12 10:21:54.553] [806432,806433] [debug] 1ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/demo] rev=1:90703, add session="d8f4f6-6b9f-254f-3877-44180aeaba61e3", address="192.168.10.137:11210", index=2
[2023-09-12 10:21:54.553] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/d8f4f6-6b9f-254f-3877-44180aeaba61e3/plain/demo] <192.168.10.137:11210> attempt to establish MCBP connection
[2023-09-12 10:21:54.554] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/demo] rev=1:90703, preserve session="88332a-a45a-7942-e771-6196e6cb000fef", address="192.168.10.138:11210", index=3->3
[2023-09-12 10:21:54.555] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/demo] rev=1:90703, add session="62937e-7967-aa49-e8b6-560b84e9ff58d6", address="192.168.10.139:11210", index=4
[2023-09-12 10:21:54.555] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/62937e-7967-aa49-e8b6-560b84e9ff58d6/plain/demo] <192.168.10.139:11210> attempt to establish MCBP connection
[2023-09-12 10:21:54.555] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/2ddf94-0923-ce47-a42f-30c81b4528399d/plain/demo] <192.168.10.131:11210> connecting to 192.168.10.131:11210, timeout=50000ms
[2023-09-12 10:21:54.556] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/a80cab-a1c9-0f4c-695d-26c163d2b61779/plain/demo] <192.168.10.135:11210> connecting to 192.168.10.135:11210, timeout=50000ms
[2023-09-12 10:21:54.556] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/d8f4f6-6b9f-254f-3877-44180aeaba61e3/plain/demo] <192.168.10.137:11210> connecting to 192.168.10.137:11210, timeout=50000ms
[2023-09-12 10:21:54.557] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/62937e-7967-aa49-e8b6-560b84e9ff58d6/plain/demo] <192.168.10.139:11210> connecting to 192.168.10.139:11210, timeout=50000ms
[2023-09-12 10:21:54.559] [806432,806433] [debug] 1ms, PYCBC: open/close bucket callback completed
[2023-09-12 10:21:54.561] [806432,806432] [debug] 2ms, QUERY: client_context_id="601d4a-28d9-6a48-21fe-e5ae302213eea3", prep=false, "SELECT META(c).id AS k,{c.custid,c.name,c.phone, c.email, c.birthday} FROM demo.test.customer AS c JOIN demo.test.orders AS i on i.custid = c.custid JOIN demo.test.address AS ad ON c.zipcode = ad.zipcode JOIN demo.test.orders_detail AS od ON od.orderno = i.orderno", options={"client_context_id":"601d4a-28d9-6a48-21fe-e5ae302213eea3","metrics":false,"query_context":"`demo`.`test`","timeout":"74500ms"}
[2023-09-12 10:21:54.562] [806432,806433] [debug] 1ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/e7dcf9-bcc7-d342-f613-cc61993847b9b2] connecting to 192.168.10.140:8093, timeout=50000ms
[2023-09-12 10:21:54.563] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/2ddf94-0923-ce47-a42f-30c81b4528399d/plain/demo] <192.168.10.131:11210> connected to 192.168.10.131:11210
[2023-09-12 10:21:54.564] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/2ddf94-0923-ce47-a42f-30c81b4528399d/plain/demo] <192.168.10.131/192.168.10.131:11210> user_agent={"a":"cxx/1.0.0/adc416d;Linux/x86_64;pycbc/4.1.6 (python/3.10.12)","i":"976b47-94fe-1749-ab1a-c5984d33c65ca1/2ddf94-0923-ce47-a42f-30c81b4528399d"}, requested_features=[tcp_nodelay, xattr, xerror, select_bucket, json, duplex, alt_request_support, tracing, sync_replication, vattr, collections, subdoc_create_as_deleted, preserve_ttl, unordered_execution, mutation_seqno]
[2023-09-12 10:21:54.564] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/a80cab-a1c9-0f4c-695d-26c163d2b61779/plain/demo] <192.168.10.135:11210> connected to 192.168.10.135:11210
[2023-09-12 10:21:54.564] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/a80cab-a1c9-0f4c-695d-26c163d2b61779/plain/demo] <192.168.10.135/192.168.10.135:11210> user_agent={"a":"cxx/1.0.0/adc416d;Linux/x86_64;pycbc/4.1.6 (python/3.10.12)","i":"976b47-94fe-1749-ab1a-c5984d33c65ca1/a80cab-a1c9-0f4c-695d-26c163d2b61779"}, requested_features=[tcp_nodelay, xattr, xerror, select_bucket, json, duplex, alt_request_support, tracing, sync_replication, vattr, collections, subdoc_create_as_deleted, preserve_ttl, unordered_execution, mutation_seqno]
[2023-09-12 10:21:54.564] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/d8f4f6-6b9f-254f-3877-44180aeaba61e3/plain/demo] <192.168.10.137:11210> connected to 192.168.10.137:11210
[2023-09-12 10:21:54.564] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/d8f4f6-6b9f-254f-3877-44180aeaba61e3/plain/demo] <192.168.10.137/192.168.10.137:11210> user_agent={"a":"cxx/1.0.0/adc416d;Linux/x86_64;pycbc/4.1.6 (python/3.10.12)","i":"976b47-94fe-1749-ab1a-c5984d33c65ca1/d8f4f6-6b9f-254f-3877-44180aeaba61e3"}, requested_features=[tcp_nodelay, xattr, xerror, select_bucket, json, duplex, alt_request_support, tracing, sync_replication, vattr, collections, subdoc_create_as_deleted, preserve_ttl, unordered_execution, mutation_seqno]
[2023-09-12 10:21:54.564] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/62937e-7967-aa49-e8b6-560b84e9ff58d6/plain/demo] <192.168.10.139:11210> connected to 192.168.10.139:11210
[2023-09-12 10:21:54.565] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/62937e-7967-aa49-e8b6-560b84e9ff58d6/plain/demo] <192.168.10.139/192.168.10.139:11210> user_agent={"a":"cxx/1.0.0/adc416d;Linux/x86_64;pycbc/4.1.6 (python/3.10.12)","i":"976b47-94fe-1749-ab1a-c5984d33c65ca1/62937e-7967-aa49-e8b6-560b84e9ff58d6"}, requested_features=[tcp_nodelay, xattr, xerror, select_bucket, json, duplex, alt_request_support, tracing, sync_replication, vattr, collections, subdoc_create_as_deleted, preserve_ttl, unordered_execution, mutation_seqno]
[2023-09-12 10:21:54.566] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/e7dcf9-bcc7-d342-f613-cc61993847b9b2] connected to 192.168.10.140:8093
[2023-09-12 10:21:54.567] [806432,806433] [debug] 1ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/2ddf94-0923-ce47-a42f-30c81b4528399d/plain/demo] <192.168.10.131/192.168.10.131:11210> supported_features=[tcp_nodelay, mutation_seqno, xattr, xerror, select_bucket, json, duplex, unordered_execution, tracing, alt_request_support, sync_replication, collections, preserve_ttl, vattr, subdoc_create_as_deleted]
[2023-09-12 10:21:54.574] [806432,806433] [debug] 6ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/d8f4f6-6b9f-254f-3877-44180aeaba61e3/plain/demo] <192.168.10.137/192.168.10.137:11210> supported_features=[tcp_nodelay, mutation_seqno, xattr, xerror, select_bucket, json, duplex, unordered_execution, tracing, alt_request_support, sync_replication, collections, preserve_ttl, vattr, subdoc_create_as_deleted]
[2023-09-12 10:21:54.579] [806432,806433] [debug] 4ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/62937e-7967-aa49-e8b6-560b84e9ff58d6/plain/demo] <192.168.10.139/192.168.10.139:11210> supported_features=[tcp_nodelay, mutation_seqno, xattr, xerror, select_bucket, json, duplex, unordered_execution, tracing, alt_request_support, sync_replication, collections, preserve_ttl, vattr, subdoc_create_as_deleted]
[2023-09-12 10:21:54.584] [806432,806433] [debug] 5ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/a80cab-a1c9-0f4c-695d-26c163d2b61779/plain/demo] <192.168.10.135/192.168.10.135:11210> supported_features=[tcp_nodelay, mutation_seqno, xattr, xerror, select_bucket, json, duplex, unordered_execution, tracing, alt_request_support, sync_replication, collections, preserve_ttl, vattr, subdoc_create_as_deleted]
[2023-09-12 10:21:54.590] [806432,806433] [debug] 5ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/d8f4f6-6b9f-254f-3877-44180aeaba61e3/plain/demo] <192.168.10.137/192.168.10.137:11210> selected bucket: demo
[2023-09-12 10:21:54.592] [806432,806433] [debug] 1ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/2ddf94-0923-ce47-a42f-30c81b4528399d/plain/demo] <192.168.10.131/192.168.10.131:11210> selected bucket: demo
[2023-09-12 10:21:54.593] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/62937e-7967-aa49-e8b6-560b84e9ff58d6/plain/demo] <192.168.10.139/192.168.10.139:11210> selected bucket: demo
[2023-09-12 10:21:54.598] [806432,806433] [debug] 4ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/a80cab-a1c9-0f4c-695d-26c163d2b61779/plain/demo] <192.168.10.135/192.168.10.135:11210> selected bucket: demo
[2023-09-12 10:23:09.088] [806432,806433] [debug] 74490ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/e7dcf9-bcc7-d342-f613-cc61993847b9b2] <192.168.10.140:8093> put HTTP session back to idle connections
Traceback (most recent call last):
  File "/home/time.py", line 66, in <module>
    timeout_test()
  File "/home/time.py", line 58, in timeout_test
    for row in result.rows():
  File "/usr/local/lib/python3.10/dist-packages/couchbase/n1ql.py", line 90, in __next__
    raise ex
  File "/usr/local/lib/python3.10/dist-packages/couchbase/n1ql.py", line 84, in __next__
    return self._get_next_row()
  File "/usr/local/lib/python3.10/dist-packages/couchbase/n1ql.py", line 75, in _get_next_row
    raise ErrorMapper.build_exception(row)
couchbase.exceptions.UnAmbiguousTimeoutException: UnAmbiguousTimeoutException(<ec=14, category=couchbase.common, message=unambiguous_timeout (14), context=QueryErrorContext({'last_dispatched_to': '192.168.10.140:8093', 'last_dispatched_from': '192.168.10.137:37550', 'retry_attempts': 0, 'client_context_id': '601d4a-28d9-6a48-21fe-e5ae302213eea3', 'method': 'POST', 'path': '/query/service', 'http_status': 200, 'http_body': '{\n"requestID": "93589c94-bf1c-4d28-ac42-a44ae73a9507",\n"clientContextID": "601d4a-28d9-6a48-21fe-e5ae302213eea3",\n"signature": {"$1":"object","k":"json"},\n"results": [\n],\n"errors": [{"code":1080,"msg":"Timeout 1m14.5s exceeded","retry":true}],\n"status": "timeout"\n}\n', 'first_error_code': 1080, 'first_error_message': 'Timeout 1m14.5s exceeded', 'statement': 'SELECT META(c).id AS k,{c.custid,c.name,c.phone, c.email, c.birthday} FROM demo.test.customer AS c JOIN demo.test.orders AS i on i.custid = c.custid JOIN demo.test.address AS ad ON c.zipcode = ad.zipcode JOIN demo.test.orders_detail AS od ON od.orderno = i.orderno', 'parameters': '{"client_context_id":"601d4a-28d9-6a48-21fe-e5ae302213eea3","metrics":false,"query_context":"`demo`.`test`","statement":"SELECT META(c).id AS k,{c.custid,c.name,c.phone, c.email, c.birthday} FROM demo.test.customer AS c JOIN demo.test.orders AS i on i.custid = c.custid JOIN demo.test.address AS ad ON c.zipcode = ad.zipcode JOIN demo.test.orders_detail AS od ON od.orderno = i.orderno","timeout":"74500ms"}', 'context_type': 'QueryErrorContext'}), C Source=/home/ec2-user/workspace/python/sdk/python-packaging-pipeline/py-client/src/n1ql.cxx:297>)
[2023-09-12 10:23:09.494] [806432,806432] [debug] 405ms, PYCBC: exception_base_dealloc completed
[2023-09-12 10:23:09.506] [806432,806432] [debug] 12ms, dealloc transaction_config
[2023-09-12 10:23:09.507] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/07c0e1-c025-584f-d48b-dfab28854536df/plain/-] <192.168.10.138/192.168.10.138:11210> stop MCBP connection, reason=do_not_retry
[2023-09-12 10:23:09.507] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/2ddf94-0923-ce47-a42f-30c81b4528399d/plain/demo] <192.168.10.131/192.168.10.131:11210> stop MCBP connection, reason=do_not_retry
[2023-09-12 10:23:09.508] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/a80cab-a1c9-0f4c-695d-26c163d2b61779/plain/demo] <192.168.10.135/192.168.10.135:11210> stop MCBP connection, reason=do_not_retry
[2023-09-12 10:23:09.508] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/d8f4f6-6b9f-254f-3877-44180aeaba61e3/plain/demo] <192.168.10.137/192.168.10.137:11210> stop MCBP connection, reason=do_not_retry
[2023-09-12 10:23:09.508] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/88332a-a45a-7942-e771-6196e6cb000fef/plain/demo] <192.168.10.138/192.168.10.138:11210> stop MCBP connection, reason=do_not_retry
[2023-09-12 10:23:09.509] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/62937e-7967-aa49-e8b6-560b84e9ff58d6/plain/demo] <192.168.10.139/192.168.10.139:11210> stop MCBP connection, reason=do_not_retry
[2023-09-12 10:23:09.510] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/07c0e1-c025-584f-d48b-dfab28854536df/plain/-] <192.168.10.138/192.168.10.138:11210> destroy MCBP connection
[2023-09-12 10:23:09.510] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/2ddf94-0923-ce47-a42f-30c81b4528399d/plain/demo] <192.168.10.131/192.168.10.131:11210> destroy MCBP connection
[2023-09-12 10:23:09.511] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/a80cab-a1c9-0f4c-695d-26c163d2b61779/plain/demo] <192.168.10.135/192.168.10.135:11210> destroy MCBP connection
[2023-09-12 10:23:09.511] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/d8f4f6-6b9f-254f-3877-44180aeaba61e3/plain/demo] <192.168.10.137/192.168.10.137:11210> destroy MCBP connection
[2023-09-12 10:23:09.512] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/88332a-a45a-7942-e771-6196e6cb000fef/plain/demo] <192.168.10.138/192.168.10.138:11210> destroy MCBP connection
[2023-09-12 10:23:09.512] [806432,806433] [debug] 0ms, [976b47-94fe-1749-ab1a-c5984d33c65ca1/62937e-7967-aa49-e8b6-560b84e9ff58d6/plain/demo] <192.168.10.139/192.168.10.139:11210> destroy MCBP connection
[2023-09-12 10:23:09.513] [806432,806432] [debug] 0ms, PYCBC: dealloc_conn completed
[2023-09-12 10:23:09.514] [806432,806432] [warning] 0ms, Operations over threshold: {"count":1,"service":"query","top":[{"last_local_id":"e7dcf9-bcc7-d342-f613-cc61993847b9b2","last_local_socket":"192.168.10.137:37550","last_operation_id":"601d4a-28d9-6a48-21fe-e5ae302213eea3","last_remote_socket":"192.168.10.140:8093","operation_name":"cb.query","total_duration_us":74518355}]}
[2023-09-12 10:23:09.515] [806432,806432] [debug] 1ms, dealloc transaction_query_options

python script :

from datetime import timedelta
# these modules are used to access and authenticate with your database cluster:
from couchbase.auth import PasswordAuthenticator
from couchbase.cluster import Cluster

# needed for options -- cluster, timeout, SQL++ (N1QL) query, etc.
from couchbase.options import (ClusterOptions, ClusterTimeoutOptions, QueryOptions)


# Update this to your cluster
username = "Administrator"
password = "password"
bucket_name = "demo"

auth = PasswordAuthenticator(
    username,
    password,
)
timeout_options = ClusterTimeoutOptions(connect_timeout=timedelta(seconds=50),kv_timeout=timedelta(seconds=50),query_timeout=timedelta(seconds=5))

cluster = Cluster('couchbase://192.168.10.138', options)

cb = cluster.bucket(bucket_name)
cb_coll = cb.scope("test").collection("test")

# Get a reference to the default collection, required for older Couchbase server versions
cb_coll_default = cb.default_collection()

test_scope = cb.scope('test')
def timeout_test():
   # query = "select count(*) as Cnt from comp_test.test.test"
    query = "SELECT META(c).id AS k,{c.custid,c.name,c.phone, c.email, c.birthday} FROM demo.test.customer AS c JOIN demo.test.orders AS i on i.custid = c.custid JOIN demo.test.address AS ad ON c.zipcode = ad.zipcode JOIN demo.test.orders_detail AS od ON od.orderno = i.orderno"
    result = test_scope.query(query)
    for row in result.rows():
        print("Found row: {}".format(row))
        No = row['Cnt'] + 1
        print('No:', No)

timeout_test()
6

For the Node.js SDK, the cluster timeouts should be provided via the TimeoutConfig in the ConnectionOptions (see API docs).

Altering the connect snippet from the example you provided:

  const cluster = await couchbase.connect(clusterConnStr, {
    username: username,
    password: password,
    timeouts: {
        queryTimeout: 5000,
    }
  });

Then you should see in the logs at the trace level (using a more recent version of the SDK, I think at least 4.2.5 maybe):

[2023-09-12 11:08:35.394] [40321,469001] [debug] 0ms, QUERY: client_context_id="6e102c-72be-cc44-973d-0e38845c1217f1", prep=false, "SELECT * FROM `default` LIMIT 10;", options={"client_context_id":"6e102c-72be-cc44-973d-0e38845c1217f1","metrics":false,"timeout":"9500ms"}
[2023-09-12 11:08:35.394] [40321,469001] [trace] 0ms, [6ab03b-78f5-2347-376b-2ea27c1bdb1247/3b5bae-8aea-6d49-f671-44f36ac4562d2a] HTTP request: query, method=POST, path="/query/service", client_context_id="6e102c-72be-cc44-973d-0e38845c1217f1", timeout=10000ms
7

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.