Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Close stream after calling appendRows error #348

Closed
jyeros opened this issue Jun 23, 2023 · 4 comments · Fixed by #439
Closed

Close stream after calling appendRows error #348

jyeros opened this issue Jun 23, 2023 · 4 comments · Fixed by #439
Assignees
Labels
api: bigquerystorage Issues related to the googleapis/nodejs-bigquery-storage API. priority: p2 Moderately-important priority. Fix may not be included in next release. type: bug Error or flaw in code with unintended results or allowing sub-optimal usage patterns.

Comments

@jyeros
Copy link

jyeros commented Jun 23, 2023

End appendRows stream without writing any data causes Error: 3 INVALID_ARGUMENT: Cannot route on empty project id ''

Environment details

  • OS: Windows 11
  • Node.js version: 18.16.0
  • yarn version: 3.5.0
  • @google-cloud/bigquery-storage version: 3.4.0

Steps to reproduce

  1. const stream = client.appendRows(...)
  2. stream.end()
@jyeros jyeros added priority: p2 Moderately-important priority. Fix may not be included in next release. type: bug Error or flaw in code with unintended results or allowing sub-optimal usage patterns. labels Jun 23, 2023
@product-auto-label product-auto-label bot added the api: bigquerystorage Issues related to the googleapis/nodejs-bigquery-storage API. label Jun 23, 2023
@loferris loferris self-assigned this Aug 16, 2023
@loferris
Copy link
Contributor

loferris commented Aug 23, 2023

Hi @jyeros - to diagnose this particular issue, I will need more details on this error, particularly the debug output from the failed RPC call. With something like this, it's important to double-check the request headers that are getting sent. You may also give our new client library package a try. You can see a sample here, which includes .close(). However, it's still using the underlying API. Closing for now, but feel free to re-open!

@jdleesmiller
Copy link

@loferris Here is a patch on the sample for the current main (1867062) that reproduces the problem.

diff --git a/samples/append_rows_pending.js b/samples/append_rows_pending.js
index 324c79d..f2cb7e6 100644
--- a/samples/append_rows_pending.js
+++ b/samples/append_rows_pending.js
@@ -20,7 +20,7 @@ function main(
   tableId = 'my_table'
 ) {
   // [START bigquerystorage_append_rows_pending]
-  const {adapt, managedwriter} = require('@google-cloud/bigquery-storage');
+  const {adapt, managedwriter} = require('../build/src');
   const {WriterClient, Writer} = managedwriter;
 
   const customer_record_pb = require('./customer_record_pb.js');
@@ -73,49 +73,6 @@ function main(
       let serializedRows = [];
       const pendingWrites = [];
 
-      // Row 1
-      let row = {
-        rowNum: 1,
-        customerName: 'Octavia',
-      };
-      serializedRows.push(CustomerRecord.encode(row).finish());
-
-      // Row 2
-      row = {
-        rowNum: 2,
-        customerName: 'Turing',
-      };
-      serializedRows.push(CustomerRecord.encode(row).finish());
-
-      // Set an offset to allow resuming this stream if the connection breaks.
-      // Keep track of which requests the server has acknowledged and resume the
-      // stream at the first non-acknowledged message. If the server has already
-      // processed a message with that offset, it will return an ALREADY_EXISTS
-      // error, which can be safely ignored.
-
-      // The first request must always have an offset of 0.
-      let offsetValue = 0;
-
-      // Send batch.
-      let pw = writer.appendRows({serializedRows}, offsetValue);
-      pendingWrites.push(pw);
-
-      serializedRows = [];
-
-      // Row 3
-      row = {
-        rowNum: 3,
-        customerName: 'Bell',
-      };
-      serializedRows.push(CustomerRecord.encode(row).finish());
-
-      // Offset must equal the number of rows that were previously sent.
-      offsetValue = 2;
-
-      // Send batch.
-      pw = writer.appendRows({serializedRows}, offsetValue);
-      pendingWrites.push(pw);
-
       const results = await Promise.all(
         pendingWrites.map(pw => pw.getResult())
       );

The results with GRPC tracing are as follows:

 GRPC_VERBOSITY=debug GRPC_TRACE=all node append_rows_pending.js REDACTED_PROJECT REDACTED_DATASET REDACTED_TABLE
D 2023-09-06T20:00:52.237Z | index | Loading @grpc/grpc-js version 1.8.21
D 2023-09-06T20:00:52.481Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 IDLE -> IDLE
D 2023-09-06T20:00:52.481Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 IDLE -> IDLE
D 2023-09-06T20:00:52.482Z | dns_resolver | Resolver constructed for target dns:bigquerystorage.googleapis.com:443
D 2023-09-06T20:00:52.483Z | channel | (1) dns:bigquerystorage.googleapis.com:443 Channel constructed with options {
  "grpc.max_receive_message_length": -1,
  "grpc.max_send_message_length": -1,
  "grpc.initial_reconnect_backoff_ms": 1000,
  "grpc.keepalive_time_ms": 30000,
  "grpc.keepalive_timeout_ms": 10000
}
D 2023-09-06T20:00:52.483Z | channel_stacktrace | (1) Channel constructed 
    at new InternalChannel (/srv/nodejs-bigquery-storage/node_modules/@grpc/grpc-js/build/src/internal-channel.js:226:23)
    at new ChannelImplementation (/srv/nodejs-bigquery-storage/node_modules/@grpc/grpc-js/build/src/channel.js:35:32)
    at new Client (/srv/nodejs-bigquery-storage/node_modules/@grpc/grpc-js/build/src/client.js:65:36)
    at new ServiceClientImpl (/srv/nodejs-bigquery-storage/node_modules/@grpc/grpc-js/build/src/make-client.js:58:5)
    at GrpcClient.createStub (/srv/nodejs-bigquery-storage/node_modules/google-gax/build/src/grpc.js:334:22)
    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
D 2023-09-06T20:00:52.485Z | channel | (1) dns:bigquerystorage.googleapis.com:443 createResolvingCall [0] method="/google.cloud.bigquery.storage.v1.BigQueryWrite/CreateWriteStream", deadline=2023-09-06T20:20:52.485Z
D 2023-09-06T20:00:52.486Z | resolving_call | [0] Created
D 2023-09-06T20:00:52.486Z | resolving_call | [0] Deadline: 2023-09-06T20:20:52.485Z
D 2023-09-06T20:00:52.486Z | resolving_call | [0] Deadline will be reached in 1199999ms
D 2023-09-06T20:00:52.486Z | resolving_call | [0] start called
D 2023-09-06T20:00:52.487Z | dns_resolver | Looking up DNS hostname bigquerystorage.googleapis.com
D 2023-09-06T20:00:52.488Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.488Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.489Z | channel | (1) dns:bigquerystorage.googleapis.com:443 callRefTimer.ref | configSelectionQueue.length=1 pickQueue.length=0
D 2023-09-06T20:00:52.489Z | resolving_call | [0] startRead called
D 2023-09-06T20:00:52.490Z | resolving_call | [0] write() called with message of length 80
D 2023-09-06T20:00:52.490Z | resolving_call | [0] halfClose called
D 2023-09-06T20:00:52.491Z | dns_resolver | Resolved addresses for target dns:bigquerystorage.googleapis.com:443: [2607:f8b0:400c:c0a::5f:443,173.194.217.95:443,2607:f8b0:400c:c0c::5f:443,173.194.218.95:443,2607:f8b0:400c:c12::5f:443,172.217.204.95:443,2607:f8b0:400c:c13::5f:443,142.250.97.95:443,142.251.107.95:443,74.125.196.95:443,142.251.162.95:443,74.125.139.95:443,173.194.210.95:443,173.194.211.95:443,173.194.213.95:443,173.194.215.95:443,173.194.216.95:443]
D 2023-09-06T20:00:52.492Z | pick_first | Connect to address list 2607:f8b0:400c:c0a::5f:443,173.194.217.95:443,2607:f8b0:400c:c0c::5f:443,173.194.218.95:443,2607:f8b0:400c:c12::5f:443,172.217.204.95:443,2607:f8b0:400c:c13::5f:443,142.250.97.95:443,142.251.107.95:443,74.125.196.95:443,142.251.162.95:443,74.125.139.95:443,173.194.210.95:443,173.194.211.95:443,173.194.213.95:443,173.194.215.95:443,173.194.216.95:443
D 2023-09-06T20:00:52.493Z | subchannel | (2) 2607:f8b0:400c:c0a::5f:443 Subchannel constructed with options {
  "grpc.max_receive_message_length": -1,
  "grpc.max_send_message_length": -1,
  "grpc.initial_reconnect_backoff_ms": 1000,
  "grpc.keepalive_time_ms": 30000,
  "grpc.keepalive_timeout_ms": 10000
}
D 2023-09-06T20:00:52.493Z | subchannel_refcount | (2) 2607:f8b0:400c:c0a::5f:443 refcount 0 -> 1
D 2023-09-06T20:00:52.493Z | subchannel | (3) 173.194.217.95:443 Subchannel constructed with options {
  "grpc.max_receive_message_length": -1,
  "grpc.max_send_message_length": -1,
  "grpc.initial_reconnect_backoff_ms": 1000,
  "grpc.keepalive_time_ms": 30000,
  "grpc.keepalive_timeout_ms": 10000
}
D 2023-09-06T20:00:52.493Z | subchannel_refcount | (3) 173.194.217.95:443 refcount 0 -> 1
D 2023-09-06T20:00:52.493Z | subchannel | (4) 2607:f8b0:400c:c0c::5f:443 Subchannel constructed with options {
  "grpc.max_receive_message_length": -1,
  "grpc.max_send_message_length": -1,
  "grpc.initial_reconnect_backoff_ms": 1000,
  "grpc.keepalive_time_ms": 30000,
  "grpc.keepalive_timeout_ms": 10000
}
D 2023-09-06T20:00:52.493Z | subchannel_refcount | (4) 2607:f8b0:400c:c0c::5f:443 refcount 0 -> 1
D 2023-09-06T20:00:52.494Z | subchannel | (5) 173.194.218.95:443 Subchannel constructed with options {
  "grpc.max_receive_message_length": -1,
  "grpc.max_send_message_length": -1,
  "grpc.initial_reconnect_backoff_ms": 1000,
  "grpc.keepalive_time_ms": 30000,
  "grpc.keepalive_timeout_ms": 10000
}
D 2023-09-06T20:00:52.494Z | subchannel_refcount | (5) 173.194.218.95:443 refcount 0 -> 1
D 2023-09-06T20:00:52.494Z | subchannel | (6) 2607:f8b0:400c:c12::5f:443 Subchannel constructed with options {
  "grpc.max_receive_message_length": -1,
  "grpc.max_send_message_length": -1,
  "grpc.initial_reconnect_backoff_ms": 1000,
  "grpc.keepalive_time_ms": 30000,
  "grpc.keepalive_timeout_ms": 10000
}
D 2023-09-06T20:00:52.494Z | subchannel_refcount | (6) 2607:f8b0:400c:c12::5f:443 refcount 0 -> 1
D 2023-09-06T20:00:52.494Z | subchannel | (7) 172.217.204.95:443 Subchannel constructed with options {
  "grpc.max_receive_message_length": -1,
  "grpc.max_send_message_length": -1,
  "grpc.initial_reconnect_backoff_ms": 1000,
  "grpc.keepalive_time_ms": 30000,
  "grpc.keepalive_timeout_ms": 10000
}
D 2023-09-06T20:00:52.494Z | subchannel_refcount | (7) 172.217.204.95:443 refcount 0 -> 1
D 2023-09-06T20:00:52.494Z | subchannel | (8) 2607:f8b0:400c:c13::5f:443 Subchannel constructed with options {
  "grpc.max_receive_message_length": -1,
  "grpc.max_send_message_length": -1,
  "grpc.initial_reconnect_backoff_ms": 1000,
  "grpc.keepalive_time_ms": 30000,
  "grpc.keepalive_timeout_ms": 10000
}
D 2023-09-06T20:00:52.494Z | subchannel_refcount | (8) 2607:f8b0:400c:c13::5f:443 refcount 0 -> 1
D 2023-09-06T20:00:52.494Z | subchannel | (9) 142.250.97.95:443 Subchannel constructed with options {
  "grpc.max_receive_message_length": -1,
  "grpc.max_send_message_length": -1,
  "grpc.initial_reconnect_backoff_ms": 1000,
  "grpc.keepalive_time_ms": 30000,
  "grpc.keepalive_timeout_ms": 10000
}
D 2023-09-06T20:00:52.494Z | subchannel_refcount | (9) 142.250.97.95:443 refcount 0 -> 1
D 2023-09-06T20:00:52.495Z | subchannel | (10) 142.251.107.95:443 Subchannel constructed with options {
  "grpc.max_receive_message_length": -1,
  "grpc.max_send_message_length": -1,
  "grpc.initial_reconnect_backoff_ms": 1000,
  "grpc.keepalive_time_ms": 30000,
  "grpc.keepalive_timeout_ms": 10000
}
D 2023-09-06T20:00:52.495Z | subchannel_refcount | (10) 142.251.107.95:443 refcount 0 -> 1
D 2023-09-06T20:00:52.495Z | subchannel | (11) 74.125.196.95:443 Subchannel constructed with options {
  "grpc.max_receive_message_length": -1,
  "grpc.max_send_message_length": -1,
  "grpc.initial_reconnect_backoff_ms": 1000,
  "grpc.keepalive_time_ms": 30000,
  "grpc.keepalive_timeout_ms": 10000
}
D 2023-09-06T20:00:52.495Z | subchannel_refcount | (11) 74.125.196.95:443 refcount 0 -> 1
D 2023-09-06T20:00:52.495Z | subchannel | (12) 142.251.162.95:443 Subchannel constructed with options {
  "grpc.max_receive_message_length": -1,
  "grpc.max_send_message_length": -1,
  "grpc.initial_reconnect_backoff_ms": 1000,
  "grpc.keepalive_time_ms": 30000,
  "grpc.keepalive_timeout_ms": 10000
}
D 2023-09-06T20:00:52.495Z | subchannel_refcount | (12) 142.251.162.95:443 refcount 0 -> 1
D 2023-09-06T20:00:52.495Z | subchannel | (13) 74.125.139.95:443 Subchannel constructed with options {
  "grpc.max_receive_message_length": -1,
  "grpc.max_send_message_length": -1,
  "grpc.initial_reconnect_backoff_ms": 1000,
  "grpc.keepalive_time_ms": 30000,
  "grpc.keepalive_timeout_ms": 10000
}
D 2023-09-06T20:00:52.495Z | subchannel_refcount | (13) 74.125.139.95:443 refcount 0 -> 1
D 2023-09-06T20:00:52.495Z | subchannel | (14) 173.194.210.95:443 Subchannel constructed with options {
  "grpc.max_receive_message_length": -1,
  "grpc.max_send_message_length": -1,
  "grpc.initial_reconnect_backoff_ms": 1000,
  "grpc.keepalive_time_ms": 30000,
  "grpc.keepalive_timeout_ms": 10000
}
D 2023-09-06T20:00:52.495Z | subchannel_refcount | (14) 173.194.210.95:443 refcount 0 -> 1
D 2023-09-06T20:00:52.495Z | subchannel | (15) 173.194.211.95:443 Subchannel constructed with options {
  "grpc.max_receive_message_length": -1,
  "grpc.max_send_message_length": -1,
  "grpc.initial_reconnect_backoff_ms": 1000,
  "grpc.keepalive_time_ms": 30000,
  "grpc.keepalive_timeout_ms": 10000
}
D 2023-09-06T20:00:52.495Z | subchannel_refcount | (15) 173.194.211.95:443 refcount 0 -> 1
D 2023-09-06T20:00:52.495Z | subchannel | (16) 173.194.213.95:443 Subchannel constructed with options {
  "grpc.max_receive_message_length": -1,
  "grpc.max_send_message_length": -1,
  "grpc.initial_reconnect_backoff_ms": 1000,
  "grpc.keepalive_time_ms": 30000,
  "grpc.keepalive_timeout_ms": 10000
}
D 2023-09-06T20:00:52.495Z | subchannel_refcount | (16) 173.194.213.95:443 refcount 0 -> 1
D 2023-09-06T20:00:52.495Z | subchannel | (17) 173.194.215.95:443 Subchannel constructed with options {
  "grpc.max_receive_message_length": -1,
  "grpc.max_send_message_length": -1,
  "grpc.initial_reconnect_backoff_ms": 1000,
  "grpc.keepalive_time_ms": 30000,
  "grpc.keepalive_timeout_ms": 10000
}
D 2023-09-06T20:00:52.495Z | subchannel_refcount | (17) 173.194.215.95:443 refcount 0 -> 1
D 2023-09-06T20:00:52.495Z | subchannel | (18) 173.194.216.95:443 Subchannel constructed with options {
  "grpc.max_receive_message_length": -1,
  "grpc.max_send_message_length": -1,
  "grpc.initial_reconnect_backoff_ms": 1000,
  "grpc.keepalive_time_ms": 30000,
  "grpc.keepalive_timeout_ms": 10000
}
D 2023-09-06T20:00:52.495Z | subchannel_refcount | (18) 173.194.216.95:443 refcount 0 -> 1
D 2023-09-06T20:00:52.495Z | subchannel_refcount | (2) 2607:f8b0:400c:c0a::5f:443 refcount 1 -> 2
D 2023-09-06T20:00:52.496Z | subchannel_refcount | (3) 173.194.217.95:443 refcount 1 -> 2
D 2023-09-06T20:00:52.496Z | subchannel_refcount | (4) 2607:f8b0:400c:c0c::5f:443 refcount 1 -> 2
D 2023-09-06T20:00:52.496Z | subchannel_refcount | (5) 173.194.218.95:443 refcount 1 -> 2
D 2023-09-06T20:00:52.496Z | subchannel_refcount | (6) 2607:f8b0:400c:c12::5f:443 refcount 1 -> 2
D 2023-09-06T20:00:52.496Z | subchannel_refcount | (7) 172.217.204.95:443 refcount 1 -> 2
D 2023-09-06T20:00:52.496Z | subchannel_refcount | (8) 2607:f8b0:400c:c13::5f:443 refcount 1 -> 2
D 2023-09-06T20:00:52.496Z | subchannel_refcount | (9) 142.250.97.95:443 refcount 1 -> 2
D 2023-09-06T20:00:52.496Z | subchannel_refcount | (10) 142.251.107.95:443 refcount 1 -> 2
D 2023-09-06T20:00:52.496Z | subchannel_refcount | (11) 74.125.196.95:443 refcount 1 -> 2
D 2023-09-06T20:00:52.496Z | subchannel_refcount | (12) 142.251.162.95:443 refcount 1 -> 2
D 2023-09-06T20:00:52.496Z | subchannel_refcount | (13) 74.125.139.95:443 refcount 1 -> 2
D 2023-09-06T20:00:52.496Z | subchannel_refcount | (14) 173.194.210.95:443 refcount 1 -> 2
D 2023-09-06T20:00:52.496Z | subchannel_refcount | (15) 173.194.211.95:443 refcount 1 -> 2
D 2023-09-06T20:00:52.496Z | subchannel_refcount | (16) 173.194.213.95:443 refcount 1 -> 2
D 2023-09-06T20:00:52.496Z | subchannel_refcount | (17) 173.194.215.95:443 refcount 1 -> 2
D 2023-09-06T20:00:52.496Z | subchannel_refcount | (18) 173.194.216.95:443 refcount 1 -> 2
D 2023-09-06T20:00:52.496Z | pick_first | Start connecting to subchannel with address 2607:f8b0:400c:c0a::5f:443
D 2023-09-06T20:00:52.496Z | pick_first | IDLE -> CONNECTING
D 2023-09-06T20:00:52.497Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.497Z | channel | (1) dns:bigquerystorage.googleapis.com:443 callRefTimer.unref | configSelectionQueue.length=1 pickQueue.length=0
D 2023-09-06T20:00:52.497Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.498Z | subchannel | (2) 2607:f8b0:400c:c0a::5f:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.498Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.498Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.498Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.498Z | subchannel | (3) 173.194.217.95:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.498Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.498Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.499Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.499Z | subchannel | (4) 2607:f8b0:400c:c0c::5f:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.499Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.499Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.499Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.499Z | subchannel | (5) 173.194.218.95:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.499Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.499Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.499Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.499Z | subchannel | (6) 2607:f8b0:400c:c12::5f:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.499Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.499Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.499Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.499Z | subchannel | (7) 172.217.204.95:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.499Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.499Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.499Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.499Z | subchannel | (8) 2607:f8b0:400c:c13::5f:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.499Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.500Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.500Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.500Z | subchannel | (9) 142.250.97.95:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.500Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.500Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.500Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.500Z | subchannel | (10) 142.251.107.95:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.500Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.500Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.500Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.500Z | subchannel | (11) 74.125.196.95:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.500Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.500Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.500Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.500Z | subchannel | (12) 142.251.162.95:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.500Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.500Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.500Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.501Z | subchannel | (13) 74.125.139.95:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.501Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.501Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.501Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.501Z | subchannel | (14) 173.194.210.95:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.501Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.501Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.501Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.501Z | subchannel | (15) 173.194.211.95:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.501Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.501Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.501Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.501Z | subchannel | (16) 173.194.213.95:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.501Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.501Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.501Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.501Z | subchannel | (17) 173.194.215.95:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.501Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.501Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.501Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.501Z | subchannel | (18) 173.194.216.95:443 IDLE -> CONNECTING
D 2023-09-06T20:00:52.501Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.501Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.501Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.502Z | transport | [object Object] creating HTTP/2 session to 2607:f8b0:400c:c0a::5f:443
D 2023-09-06T20:00:52.504Z | transport | [object Object] creating HTTP/2 session to 173.194.217.95:443
D 2023-09-06T20:00:52.505Z | transport | [object Object] creating HTTP/2 session to 2607:f8b0:400c:c0c::5f:443
D 2023-09-06T20:00:52.505Z | transport | [object Object] creating HTTP/2 session to 173.194.218.95:443
D 2023-09-06T20:00:52.506Z | transport | [object Object] creating HTTP/2 session to 2607:f8b0:400c:c12::5f:443
D 2023-09-06T20:00:52.506Z | transport | [object Object] creating HTTP/2 session to 172.217.204.95:443
D 2023-09-06T20:00:52.506Z | transport | [object Object] creating HTTP/2 session to 2607:f8b0:400c:c13::5f:443
D 2023-09-06T20:00:52.507Z | transport | [object Object] creating HTTP/2 session to 142.250.97.95:443
D 2023-09-06T20:00:52.507Z | transport | [object Object] creating HTTP/2 session to 142.251.107.95:443
D 2023-09-06T20:00:52.507Z | transport | [object Object] creating HTTP/2 session to 74.125.196.95:443
D 2023-09-06T20:00:52.508Z | transport | [object Object] creating HTTP/2 session to 142.251.162.95:443
D 2023-09-06T20:00:52.508Z | transport | [object Object] creating HTTP/2 session to 74.125.139.95:443
D 2023-09-06T20:00:52.509Z | transport | [object Object] creating HTTP/2 session to 173.194.210.95:443
D 2023-09-06T20:00:52.509Z | transport | [object Object] creating HTTP/2 session to 173.194.211.95:443
D 2023-09-06T20:00:52.509Z | transport | [object Object] creating HTTP/2 session to 173.194.213.95:443
D 2023-09-06T20:00:52.510Z | transport | [object Object] creating HTTP/2 session to 173.194.215.95:443
D 2023-09-06T20:00:52.510Z | transport | [object Object] creating HTTP/2 session to 173.194.216.95:443
D 2023-09-06T20:00:52.511Z | channel | (1) dns:bigquerystorage.googleapis.com:443 createRetryingCall [1] method="/google.cloud.bigquery.storage.v1.BigQueryWrite/CreateWriteStream"
D 2023-09-06T20:00:52.511Z | resolving_call | [0] Created child [1]
D 2023-09-06T20:00:52.511Z | retrying_call | [1] start called
D 2023-09-06T20:00:52.511Z | channel | (1) dns:bigquerystorage.googleapis.com:443 createLoadBalancingCall [2] method="/google.cloud.bigquery.storage.v1.BigQueryWrite/CreateWriteStream"
D 2023-09-06T20:00:52.511Z | retrying_call | [1] Created child call [2] for attempt 1
D 2023-09-06T20:00:52.511Z | load_balancing_call | [2] start called
D 2023-09-06T20:00:52.512Z | load_balancing_call | [2] Pick called
D 2023-09-06T20:00:52.512Z | load_balancing_call | [2] Pick result: QUEUE subchannel: null status: undefined undefined
D 2023-09-06T20:00:52.512Z | channel | (1) dns:bigquerystorage.googleapis.com:443 callRefTimer.ref | configSelectionQueue.length=0 pickQueue.length=1
D 2023-09-06T20:00:52.512Z | retrying_call | [1] startRead called
D 2023-09-06T20:00:52.512Z | load_balancing_call | [2] startRead called
D 2023-09-06T20:00:52.513Z | retrying_call | [1] write() called with message of length 85
D 2023-09-06T20:00:52.513Z | load_balancing_call | [2] write() called with message of length 85
D 2023-09-06T20:00:52.513Z | retrying_call | [1] halfClose called
D 2023-09-06T20:00:52.516Z | transport | [object Object] connection failed with error connect ENETUNREACH 2607:f8b0:400c:c0a::5f:443 - Local (:::0)
D 2023-09-06T20:00:52.516Z | transport | [object Object] connection failed with error connect ENETUNREACH 2607:f8b0:400c:c0c::5f:443 - Local (:::0)
D 2023-09-06T20:00:52.516Z | transport | [object Object] connection failed with error connect ENETUNREACH 2607:f8b0:400c:c12::5f:443 - Local (:::0)
D 2023-09-06T20:00:52.516Z | transport | [object Object] connection failed with error connect ENETUNREACH 2607:f8b0:400c:c13::5f:443 - Local (:::0)
D 2023-09-06T20:00:52.516Z | subchannel | (2) 2607:f8b0:400c:c0a::5f:443 CONNECTING -> TRANSIENT_FAILURE
D 2023-09-06T20:00:52.517Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.517Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.517Z | channel | (1) dns:bigquerystorage.googleapis.com:443 callRefTimer.unref | configSelectionQueue.length=0 pickQueue.length=0
D 2023-09-06T20:00:52.517Z | load_balancing_call | [2] Pick called
D 2023-09-06T20:00:52.517Z | load_balancing_call | [2] Pick result: QUEUE subchannel: null status: undefined undefined
D 2023-09-06T20:00:52.517Z | channel | (1) dns:bigquerystorage.googleapis.com:443 callRefTimer.ref | configSelectionQueue.length=0 pickQueue.length=1
D 2023-09-06T20:00:52.517Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.517Z | subchannel | (4) 2607:f8b0:400c:c0c::5f:443 CONNECTING -> TRANSIENT_FAILURE
D 2023-09-06T20:00:52.517Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.517Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.517Z | channel | (1) dns:bigquerystorage.googleapis.com:443 callRefTimer.unref | configSelectionQueue.length=0 pickQueue.length=0
D 2023-09-06T20:00:52.517Z | load_balancing_call | [2] Pick called
D 2023-09-06T20:00:52.517Z | load_balancing_call | [2] Pick result: QUEUE subchannel: null status: undefined undefined
D 2023-09-06T20:00:52.517Z | channel | (1) dns:bigquerystorage.googleapis.com:443 callRefTimer.ref | configSelectionQueue.length=0 pickQueue.length=1
D 2023-09-06T20:00:52.517Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.517Z | subchannel | (6) 2607:f8b0:400c:c12::5f:443 CONNECTING -> TRANSIENT_FAILURE
D 2023-09-06T20:00:52.517Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.517Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.517Z | channel | (1) dns:bigquerystorage.googleapis.com:443 callRefTimer.unref | configSelectionQueue.length=0 pickQueue.length=0
D 2023-09-06T20:00:52.517Z | load_balancing_call | [2] Pick called
D 2023-09-06T20:00:52.517Z | load_balancing_call | [2] Pick result: QUEUE subchannel: null status: undefined undefined
D 2023-09-06T20:00:52.517Z | channel | (1) dns:bigquerystorage.googleapis.com:443 callRefTimer.ref | configSelectionQueue.length=0 pickQueue.length=1
D 2023-09-06T20:00:52.517Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.518Z | subchannel | (8) 2607:f8b0:400c:c13::5f:443 CONNECTING -> TRANSIENT_FAILURE
D 2023-09-06T20:00:52.518Z | pick_first | CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.518Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.518Z | channel | (1) dns:bigquerystorage.googleapis.com:443 callRefTimer.unref | configSelectionQueue.length=0 pickQueue.length=0
D 2023-09-06T20:00:52.518Z | load_balancing_call | [2] Pick called
D 2023-09-06T20:00:52.518Z | load_balancing_call | [2] Pick result: QUEUE subchannel: null status: undefined undefined
D 2023-09-06T20:00:52.518Z | channel | (1) dns:bigquerystorage.googleapis.com:443 callRefTimer.ref | configSelectionQueue.length=0 pickQueue.length=1
D 2023-09-06T20:00:52.518Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> CONNECTING
D 2023-09-06T20:00:52.525Z | subchannel | (3) 173.194.217.95:443 CONNECTING -> READY
D 2023-09-06T20:00:52.525Z | pick_first | Pick subchannel with address 173.194.217.95:443
D 2023-09-06T20:00:52.526Z | subchannel_refcount | (3) 173.194.217.95:443 refcount 2 -> 3
D 2023-09-06T20:00:52.526Z | subchannel_refcount | (2) 2607:f8b0:400c:c0a::5f:443 refcount 2 -> 1
D 2023-09-06T20:00:52.526Z | subchannel_refcount | (3) 173.194.217.95:443 refcount 3 -> 2
D 2023-09-06T20:00:52.526Z | subchannel_refcount | (4) 2607:f8b0:400c:c0c::5f:443 refcount 2 -> 1
D 2023-09-06T20:00:52.526Z | subchannel_refcount | (5) 173.194.218.95:443 refcount 2 -> 1
D 2023-09-06T20:00:52.526Z | subchannel_refcount | (6) 2607:f8b0:400c:c12::5f:443 refcount 2 -> 1
D 2023-09-06T20:00:52.526Z | subchannel_refcount | (7) 172.217.204.95:443 refcount 2 -> 1
D 2023-09-06T20:00:52.526Z | subchannel_refcount | (8) 2607:f8b0:400c:c13::5f:443 refcount 2 -> 1
D 2023-09-06T20:00:52.526Z | subchannel_refcount | (9) 142.250.97.95:443 refcount 2 -> 1
D 2023-09-06T20:00:52.526Z | subchannel_refcount | (10) 142.251.107.95:443 refcount 2 -> 1
D 2023-09-06T20:00:52.526Z | subchannel_refcount | (11) 74.125.196.95:443 refcount 2 -> 1
D 2023-09-06T20:00:52.526Z | subchannel_refcount | (12) 142.251.162.95:443 refcount 2 -> 1
D 2023-09-06T20:00:52.526Z | subchannel_refcount | (13) 74.125.139.95:443 refcount 2 -> 1
D 2023-09-06T20:00:52.526Z | subchannel_refcount | (14) 173.194.210.95:443 refcount 2 -> 1
D 2023-09-06T20:00:52.526Z | subchannel_refcount | (15) 173.194.211.95:443 refcount 2 -> 1
D 2023-09-06T20:00:52.526Z | subchannel_refcount | (16) 173.194.213.95:443 refcount 2 -> 1
D 2023-09-06T20:00:52.526Z | subchannel_refcount | (17) 173.194.215.95:443 refcount 2 -> 1
D 2023-09-06T20:00:52.526Z | subchannel_refcount | (18) 173.194.216.95:443 refcount 2 -> 1
D 2023-09-06T20:00:52.527Z | pick_first | CONNECTING -> READY
D 2023-09-06T20:00:52.527Z | resolving_load_balancer | dns:bigquerystorage.googleapis.com:443 CONNECTING -> READY
D 2023-09-06T20:00:52.527Z | channel | (1) dns:bigquerystorage.googleapis.com:443 callRefTimer.unref | configSelectionQueue.length=0 pickQueue.length=0
D 2023-09-06T20:00:52.527Z | load_balancing_call | [2] Pick called
D 2023-09-06T20:00:52.527Z | load_balancing_call | [2] Pick result: COMPLETE subchannel: (3) 173.194.217.95:443 status: undefined undefined
D 2023-09-06T20:00:52.532Z | connectivity_state | (1) dns:bigquerystorage.googleapis.com:443 CONNECTING -> READY
D 2023-09-06T20:00:52.536Z | subchannel | (5) 173.194.218.95:443 CONNECTING -> READY
D 2023-09-06T20:00:52.538Z | subchannel | (7) 172.217.204.95:443 CONNECTING -> READY
D 2023-09-06T20:00:52.541Z | subchannel | (9) 142.250.97.95:443 CONNECTING -> READY
D 2023-09-06T20:00:52.543Z | subchannel | (11) 74.125.196.95:443 CONNECTING -> READY
D 2023-09-06T20:00:52.546Z | subchannel | (12) 142.251.162.95:443 CONNECTING -> READY
D 2023-09-06T20:00:52.548Z | subchannel | (13) 74.125.139.95:443 CONNECTING -> READY
D 2023-09-06T20:00:52.550Z | subchannel | (15) 173.194.211.95:443 CONNECTING -> READY
D 2023-09-06T20:00:52.553Z | subchannel | (14) 173.194.210.95:443 CONNECTING -> READY
D 2023-09-06T20:00:52.556Z | subchannel | (10) 142.251.107.95:443 CONNECTING -> READY
D 2023-09-06T20:00:52.558Z | subchannel | (17) 173.194.215.95:443 CONNECTING -> READY
D 2023-09-06T20:00:52.561Z | subchannel | (16) 173.194.213.95:443 CONNECTING -> READY
D 2023-09-06T20:00:52.563Z | subchannel | (18) 173.194.216.95:443 CONNECTING -> READY
D 2023-09-06T20:00:52.564Z | transport | (19) 173.194.217.95:443 local settings acknowledged by remote: {"headerTableSize":4096,"enablePush":true,"initialWindowSize":65535,"maxFrameSize":16384,"maxConcurrentStreams":4294967295,"maxHeaderListSize":4294967295,"maxHeaderSize":4294967295,"enableConnectProtocol":false}
D 2023-09-06T20:00:52.564Z | transport | (20) 173.194.218.95:443 local settings acknowledged by remote: {"headerTableSize":4096,"enablePush":true,"initialWindowSize":65535,"maxFrameSize":16384,"maxConcurrentStreams":4294967295,"maxHeaderListSize":4294967295,"maxHeaderSize":4294967295,"enableConnectProtocol":false}
D 2023-09-06T20:00:52.564Z | transport | (21) 172.217.204.95:443 local settings acknowledged by remote: {"headerTableSize":4096,"enablePush":true,"initialWindowSize":65535,"maxFrameSize":16384,"maxConcurrentStreams":4294967295,"maxHeaderListSize":4294967295,"maxHeaderSize":4294967295,"enableConnectProtocol":false}
D 2023-09-06T20:00:52.564Z | transport | (22) 142.250.97.95:443 local settings acknowledged by remote: {"headerTableSize":4096,"enablePush":true,"initialWindowSize":65535,"maxFrameSize":16384,"maxConcurrentStreams":4294967295,"maxHeaderListSize":4294967295,"maxHeaderSize":4294967295,"enableConnectProtocol":false}
D 2023-09-06T20:00:52.565Z | transport | (23) 74.125.196.95:443 local settings acknowledged by remote: {"headerTableSize":4096,"enablePush":true,"initialWindowSize":65535,"maxFrameSize":16384,"maxConcurrentStreams":4294967295,"maxHeaderListSize":4294967295,"maxHeaderSize":4294967295,"enableConnectProtocol":false}
D 2023-09-06T20:00:52.565Z | transport | (24) 142.251.162.95:443 local settings acknowledged by remote: {"headerTableSize":4096,"enablePush":true,"initialWindowSize":65535,"maxFrameSize":16384,"maxConcurrentStreams":4294967295,"maxHeaderListSize":4294967295,"maxHeaderSize":4294967295,"enableConnectProtocol":false}
D 2023-09-06T20:00:52.565Z | transport | (25) 74.125.139.95:443 local settings acknowledged by remote: {"headerTableSize":4096,"enablePush":true,"initialWindowSize":65535,"maxFrameSize":16384,"maxConcurrentStreams":4294967295,"maxHeaderListSize":4294967295,"maxHeaderSize":4294967295,"enableConnectProtocol":false}
D 2023-09-06T20:00:52.565Z | transport | (27) 173.194.210.95:443 local settings acknowledged by remote: {"headerTableSize":4096,"enablePush":true,"initialWindowSize":65535,"maxFrameSize":16384,"maxConcurrentStreams":4294967295,"maxHeaderListSize":4294967295,"maxHeaderSize":4294967295,"enableConnectProtocol":false}
D 2023-09-06T20:00:52.565Z | transport | (28) 142.251.107.95:443 local settings acknowledged by remote: {"headerTableSize":4096,"enablePush":true,"initialWindowSize":65535,"maxFrameSize":16384,"maxConcurrentStreams":4294967295,"maxHeaderListSize":4294967295,"maxHeaderSize":4294967295,"enableConnectProtocol":false}
D 2023-09-06T20:00:52.565Z | transport | (29) 173.194.215.95:443 local settings acknowledged by remote: {"headerTableSize":4096,"enablePush":true,"initialWindowSize":65535,"maxFrameSize":16384,"maxConcurrentStreams":4294967295,"maxHeaderListSize":4294967295,"maxHeaderSize":4294967295,"enableConnectProtocol":false}
D 2023-09-06T20:00:52.565Z | transport | (30) 173.194.213.95:443 local settings acknowledged by remote: {"headerTableSize":4096,"enablePush":true,"initialWindowSize":65535,"maxFrameSize":16384,"maxConcurrentStreams":4294967295,"maxHeaderListSize":4294967295,"maxHeaderSize":4294967295,"enableConnectProtocol":false}
D 2023-09-06T20:00:52.566Z | transport | (31) 173.194.216.95:443 local settings acknowledged by remote: {"headerTableSize":4096,"enablePush":true,"initialWindowSize":65535,"maxFrameSize":16384,"maxConcurrentStreams":4294967295,"maxHeaderListSize":4294967295,"maxHeaderSize":4294967295,"enableConnectProtocol":false}
D 2023-09-06T20:00:52.566Z | transport | (26) 173.194.211.95:443 local settings acknowledged by remote: {"headerTableSize":4096,"enablePush":true,"initialWindowSize":65535,"maxFrameSize":16384,"maxConcurrentStreams":4294967295,"maxHeaderListSize":4294967295,"maxHeaderSize":4294967295,"enableConnectProtocol":false}
D 2023-09-06T20:00:52.573Z | transport_flowctrl | (19) 173.194.217.95:443 local window size: 65535 remote window size: 1048576
D 2023-09-06T20:00:52.574Z | transport_internals | (19) 173.194.217.95:443 session.closed=false session.destroyed=false session.socket.destroyed=false
D 2023-09-06T20:00:52.574Z | keepalive | (19) 173.194.217.95:443 Starting keepalive timer for 30000ms
D 2023-09-06T20:00:52.574Z | load_balancing_call | [2] Created child call [3]
D 2023-09-06T20:00:52.574Z | subchannel_call | [3] write() called with message of length 85
D 2023-09-06T20:00:52.574Z | subchannel_call | [3] sending data chunk of length 85
D 2023-09-06T20:00:52.575Z | load_balancing_call | [2] halfClose called
D 2023-09-06T20:00:52.575Z | subchannel_call | [3] end() called
D 2023-09-06T20:00:52.575Z | subchannel_call | [3] calling end() on HTTP/2 stream
D 2023-09-06T20:00:52.692Z | subchannel_call | [3] Received server headers:
                :status: 200
                content-disposition: attachment
                content-type: application/grpc
                date: Wed, 06 Sep 2023 20:00:52 GMT

D 2023-09-06T20:00:52.692Z | load_balancing_call | [2] Received metadata
D 2023-09-06T20:00:52.692Z | retrying_call | [1] Received metadata from child [2]
D 2023-09-06T20:00:52.692Z | retrying_call | [1] Committing call [2] at index 0
D 2023-09-06T20:00:52.692Z | resolving_call | [0] Received metadata
D 2023-09-06T20:00:52.693Z | subchannel_call | [3] receive HTTP/2 data frame of length 261
D 2023-09-06T20:00:52.693Z | subchannel_call | [3] parsed message of length 261
D 2023-09-06T20:00:52.693Z | subchannel_call | [3] pushing to reader message of length 261
D 2023-09-06T20:00:52.693Z | load_balancing_call | [2] Received message
D 2023-09-06T20:00:52.694Z | retrying_call | [1] Received message from child [2]
D 2023-09-06T20:00:52.694Z | resolving_call | [0] Received message
D 2023-09-06T20:00:52.694Z | resolving_call | [0] Finished filtering received message
D 2023-09-06T20:00:52.698Z | subchannel_call | [3] Received server trailers:
                grpc-status: 0
                content-disposition: attachment

D 2023-09-06T20:00:52.698Z | subchannel_call | [3] received status code 0 from server
D 2023-09-06T20:00:52.698Z | subchannel_call | [3] close http2 stream with code 0
D 2023-09-06T20:00:52.699Z | subchannel_call | [3] ended with status: code=0 details=""
D 2023-09-06T20:00:52.699Z | load_balancing_call | [2] Received status
D 2023-09-06T20:00:52.699Z | load_balancing_call | [2] ended with status: code=0 details=""
D 2023-09-06T20:00:52.699Z | retrying_call | [1] Received status from child [2]
D 2023-09-06T20:00:52.699Z | retrying_call | [1] state=COMMITTED handling status with progress PROCESSED from child [2] in state ACTIVE
D 2023-09-06T20:00:52.700Z | retrying_call | [1] ended with status: code=0 details=""
D 2023-09-06T20:00:52.700Z | resolving_call | [0] Received status
D 2023-09-06T20:00:52.700Z | resolving_call | [0] ended with status: code=0 details=""
D 2023-09-06T20:00:52.700Z | subchannel_call | [3] HTTP/2 stream closed with code 0
Stream created: projects/REDACTED_PROJECT/datasets/REDACTED_DATASET/tables/REDACTED_TABLE/streams/CicREDACTED
D 2023-09-06T20:00:52.702Z | channel | (1) dns:bigquerystorage.googleapis.com:443 createResolvingCall [4] method="/google.cloud.bigquery.storage.v1.BigQueryWrite/AppendRows", deadline=2023-09-07T20:00:52.702Z
D 2023-09-06T20:00:52.703Z | resolving_call | [4] Created
D 2023-09-06T20:00:52.703Z | resolving_call | [4] Deadline: 2023-09-07T20:00:52.702Z
D 2023-09-06T20:00:52.703Z | resolving_call | [4] Deadline will be reached in 86399999ms
D 2023-09-06T20:00:52.703Z | resolving_call | [4] start called
D 2023-09-06T20:00:52.703Z | resolving_call | [4] startRead called
Write results: []
D 2023-09-06T20:00:52.705Z | resolving_call | [4] halfClose called
D 2023-09-06T20:00:52.705Z | channel | (1) dns:bigquerystorage.googleapis.com:443 createRetryingCall [5] method="/google.cloud.bigquery.storage.v1.BigQueryWrite/AppendRows"
D 2023-09-06T20:00:52.705Z | resolving_call | [4] Created child [5]
D 2023-09-06T20:00:52.705Z | retrying_call | [5] start called
D 2023-09-06T20:00:52.705Z | channel | (1) dns:bigquerystorage.googleapis.com:443 createLoadBalancingCall [6] method="/google.cloud.bigquery.storage.v1.BigQueryWrite/AppendRows"
D 2023-09-06T20:00:52.706Z | retrying_call | [5] Created child call [6] for attempt 1
D 2023-09-06T20:00:52.706Z | load_balancing_call | [6] start called
D 2023-09-06T20:00:52.706Z | load_balancing_call | [6] Pick called
D 2023-09-06T20:00:52.706Z | load_balancing_call | [6] Pick result: COMPLETE subchannel: (3) 173.194.217.95:443 status: undefined undefined
D 2023-09-06T20:00:52.706Z | retrying_call | [5] startRead called
D 2023-09-06T20:00:52.706Z | load_balancing_call | [6] startRead called
D 2023-09-06T20:00:52.706Z | retrying_call | [5] halfClose called
D 2023-09-06T20:00:52.706Z | load_balancing_call | [6] halfClose called
D 2023-09-06T20:00:52.706Z | channel | (1) dns:bigquerystorage.googleapis.com:443 createResolvingCall [7] method="/google.cloud.bigquery.storage.v1.BigQueryWrite/FinalizeWriteStream", deadline=2023-09-06T20:10:52.706Z
D 2023-09-06T20:00:52.706Z | resolving_call | [7] Created
D 2023-09-06T20:00:52.706Z | resolving_call | [7] Deadline: 2023-09-06T20:10:52.706Z
D 2023-09-06T20:00:52.706Z | resolving_call | [7] Deadline will be reached in 600000ms
D 2023-09-06T20:00:52.706Z | resolving_call | [7] start called
D 2023-09-06T20:00:52.706Z | resolving_call | [7] startRead called
D 2023-09-06T20:00:52.707Z | resolving_call | [7] write() called with message of length 141
D 2023-09-06T20:00:52.707Z | resolving_call | [7] halfClose called
D 2023-09-06T20:00:52.708Z | transport_flowctrl | (19) 173.194.217.95:443 local window size: 65274 remote window size: 1048491
D 2023-09-06T20:00:52.708Z | transport_internals | (19) 173.194.217.95:443 session.closed=false session.destroyed=false session.socket.destroyed=false
D 2023-09-06T20:00:52.708Z | load_balancing_call | [6] Created child call [8]
D 2023-09-06T20:00:52.708Z | subchannel_call | [8] end() called
D 2023-09-06T20:00:52.708Z | subchannel_call | [8] calling end() on HTTP/2 stream
D 2023-09-06T20:00:52.708Z | channel | (1) dns:bigquerystorage.googleapis.com:443 createRetryingCall [9] method="/google.cloud.bigquery.storage.v1.BigQueryWrite/FinalizeWriteStream"
D 2023-09-06T20:00:52.708Z | resolving_call | [7] Created child [9]
D 2023-09-06T20:00:52.708Z | retrying_call | [9] start called
D 2023-09-06T20:00:52.708Z | channel | (1) dns:bigquerystorage.googleapis.com:443 createLoadBalancingCall [10] method="/google.cloud.bigquery.storage.v1.BigQueryWrite/FinalizeWriteStream"
D 2023-09-06T20:00:52.708Z | retrying_call | [9] Created child call [10] for attempt 1
D 2023-09-06T20:00:52.708Z | load_balancing_call | [10] start called
D 2023-09-06T20:00:52.708Z | load_balancing_call | [10] Pick called
D 2023-09-06T20:00:52.708Z | load_balancing_call | [10] Pick result: COMPLETE subchannel: (3) 173.194.217.95:443 status: undefined undefined
D 2023-09-06T20:00:52.708Z | retrying_call | [9] startRead called
D 2023-09-06T20:00:52.708Z | load_balancing_call | [10] startRead called
D 2023-09-06T20:00:52.709Z | transport_flowctrl | (19) 173.194.217.95:443 local window size: 65274 remote window size: 1048491
D 2023-09-06T20:00:52.709Z | transport_internals | (19) 173.194.217.95:443 session.closed=false session.destroyed=false session.socket.destroyed=false
D 2023-09-06T20:00:52.709Z | load_balancing_call | [10] Created child call [11]
D 2023-09-06T20:00:52.709Z | retrying_call | [9] write() called with message of length 146
D 2023-09-06T20:00:52.709Z | load_balancing_call | [10] write() called with message of length 146
D 2023-09-06T20:00:52.709Z | subchannel_call | [11] write() called with message of length 146
D 2023-09-06T20:00:52.709Z | subchannel_call | [11] sending data chunk of length 146
D 2023-09-06T20:00:52.709Z | retrying_call | [9] halfClose called
D 2023-09-06T20:00:52.712Z | load_balancing_call | [10] halfClose called
D 2023-09-06T20:00:52.712Z | subchannel_call | [11] end() called
D 2023-09-06T20:00:52.712Z | subchannel_call | [11] calling end() on HTTP/2 stream
D 2023-09-06T20:00:52.713Z | subchannel_call | [8] Received server headers:
                :status: 200
                content-type: application/grpc+proto
                date: Wed, 06 Sep 2023 20:00:52 GMT

D 2023-09-06T20:00:52.714Z | load_balancing_call | [6] Received metadata
D 2023-09-06T20:00:52.714Z | retrying_call | [5] Received metadata from child [6]
D 2023-09-06T20:00:52.714Z | retrying_call | [5] Committing call [6] at index 0
D 2023-09-06T20:00:52.714Z | resolving_call | [4] Received metadata
D 2023-09-06T20:00:52.714Z | subchannel_call | [8] Received server trailers:
                grpc-status: 3
                grpc-message: Cannot route on empty project id ''

D 2023-09-06T20:00:52.714Z | subchannel_call | [8] received status code 3 from server
D 2023-09-06T20:00:52.714Z | subchannel_call | [8] received status details string "Cannot route on empty project id ''" from server
D 2023-09-06T20:00:52.714Z | subchannel_call | [8] ended with status: code=3 details="Cannot route on empty project id ''"
D 2023-09-06T20:00:52.714Z | subchannel_call | [8] close http2 stream with code 8
D 2023-09-06T20:00:52.714Z | load_balancing_call | [6] Received status
D 2023-09-06T20:00:52.714Z | load_balancing_call | [6] ended with status: code=3 details="Cannot route on empty project id ''"
D 2023-09-06T20:00:52.714Z | retrying_call | [5] Received status from child [6]
D 2023-09-06T20:00:52.715Z | retrying_call | [5] state=COMMITTED handling status with progress PROCESSED from child [6] in state ACTIVE
D 2023-09-06T20:00:52.715Z | retrying_call | [5] ended with status: code=3 details="Cannot route on empty project id ''"
D 2023-09-06T20:00:52.715Z | resolving_call | [4] Received status
D 2023-09-06T20:00:52.715Z | resolving_call | [4] ended with status: code=3 details="Cannot route on empty project id ''"
node:events:492
      throw er; // Unhandled 'error' event
      ^

Error: 3 INVALID_ARGUMENT: Cannot route on empty project id ''
    at callErrorFromStatus (/srv/nodejs-bigquery-storage/node_modules/@grpc/grpc-js/build/src/call.js:31:19)
    at Object.onReceiveStatus (/srv/nodejs-bigquery-storage/node_modules/@grpc/grpc-js/build/src/client.js:419:73)
    at Object.onReceiveStatus (/srv/nodejs-bigquery-storage/node_modules/@grpc/grpc-js/build/src/client-interceptors.js:323:181)
    at /srv/nodejs-bigquery-storage/node_modules/@grpc/grpc-js/build/src/resolving-call.js:94:78
    at process.processTicksAndRejections (node:internal/process/task_queues:77:11)
for call at
    at ServiceClientImpl.makeBidiStreamRequest (/srv/nodejs-bigquery-storage/node_modules/@grpc/grpc-js/build/src/client.js:403:32)
    at ServiceClientImpl.<anonymous> (/srv/nodejs-bigquery-storage/node_modules/@grpc/grpc-js/build/src/make-client.js:105:19)
    at /srv/nodejs-bigquery-storage/build/src/v1/big_query_write_client.js:210:29
    at /srv/nodejs-bigquery-storage/node_modules/google-gax/build/src/streamingCalls/streamingApiCaller.js:46:28
    at /srv/nodejs-bigquery-storage/node_modules/google-gax/build/src/normalCalls/timeout.js:44:16
    at StreamProxy.setStream (/srv/nodejs-bigquery-storage/node_modules/google-gax/build/src/streamingCalls/streaming.js:144:24)
    at StreamingApiCaller.call (/srv/nodejs-bigquery-storage/node_modules/google-gax/build/src/streamingCalls/streamingApiCaller.js:54:16)
    at /srv/nodejs-bigquery-storage/node_modules/google-gax/build/src/createApiCall.js:84:30
Emitted 'error' event on StreamProxy instance at:
    at Duplexify._destroy (/srv/nodejs-bigquery-storage/node_modules/duplexify/index.js:195:15)
    at /srv/nodejs-bigquery-storage/node_modules/duplexify/index.js:185:10
    at process.processTicksAndRejections (node:internal/process/task_queues:77:11) {
  code: 3,
  details: "Cannot route on empty project id ''",
  metadata: Metadata { internalRepr: Map(0) {}, options: {} }
}

Node.js v18.17.1

It looks like it is the FinalizeWriteStream RPC that is causing the problem, but that is about all I can say. Is that the output you need?

@shollyman shollyman reopened this Sep 13, 2023
@alvarowolfx alvarowolfx self-assigned this Feb 6, 2024
@z3z1ma
Copy link

z3z1ma commented Apr 11, 2024

Getting really railed by this same issue. Using the async write client in Python.

@alvarowolfx
Copy link
Contributor

@z3z1ma @jdleesmiller @jyeros sorry for the delay on this, I managed to reproduce the issue and created PR #439 to fix this issue. Once is merged I'll publish a new version with the fix.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
api: bigquerystorage Issues related to the googleapis/nodejs-bigquery-storage API. priority: p2 Moderately-important priority. Fix may not be included in next release. type: bug Error or flaw in code with unintended results or allowing sub-optimal usage patterns.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

6 participants