Skip to content

Instantly share code, notes, and snippets.

@nvanbenschoten

nvanbenschoten/trace_1.txt

Created July 8, 2020 18:36
Show Gist options
  • Save nvanbenschoten/30536c68b43457ed4317b6ec55ea8286 to your computer and use it in GitHub Desktop.
Save nvanbenschoten/30536c68b43457ed4317b6ec55ea8286 to your computer and use it in GitHub Desktop.
Download ZIP
Missing row traces - issue #513
Raw
trace_1.txt
timestamp | age | message | tag | location | operation | span
-----------------------------------+-----------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------------------------------------------------+----------+---------------------------------------------+-------
2020-07-08 18:33:02.037857+00:00 | 00:00:00 | === SPAN START: session recording === | | | session recording | 0
2020-07-08 18:33:02.03787+00:00 | 00:00:00.000013 | === SPAN START: exec stmt === | | | exec stmt | 1
2020-07-08 18:33:02.037962+00:00 | 00:00:00.000105 | [NoTxn pos:1] executing ExecStmt: SELECT l.id IS NULL, p.port_index IS NULL, a.type IS NULL, s.stream IS NULL, i.channel_id IS NULL FROM logical_port AS l INNER JOIN appliance_physical_port AS p ON l.physical_port = p.id INNER JOIN appliance AS a ON a.id = p.appliance INNER JOIN source AS s ON s.logical_port = l.id LEFT JOIN input AS i ON i.id = s.input WHERE a.id = 'a64eda8d-5114-4f75-9ac2-8b8ff0002bd9' | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 1
2020-07-08 18:33:02.037982+00:00 | 00:00:00.000125 | executing: SELECT l.id IS NULL, p.port_index IS NULL, a.type IS NULL, s.stream IS NULL, i.channel_id IS NULL FROM logical_port AS l INNER JOIN appliance_physical_port AS p ON l.physical_port = p.id INNER JOIN appliance AS a ON a.id = p.appliance INNER JOIN source AS s ON s.logical_port = l.id LEFT JOIN input AS i ON i.id = s.input WHERE a.id = 'a64eda8d-5114-4f75-9ac2-8b8ff0002bd9' in state: NoTxn | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 1
2020-07-08 18:33:02.037993+00:00 | 00:00:00.000136 | === SPAN START: sql txn === | | | sql txn | 2
2020-07-08 18:33:02.038017+00:00 | 00:00:00.00016 | === SPAN START: exec stmt === | | | exec stmt | 3
2020-07-08 18:33:02.038038+00:00 | 00:00:00.000181 | [Open pos:1] executing ExecStmt: SELECT l.id IS NULL, p.port_index IS NULL, a.type IS NULL, s.stream IS NULL, i.channel_id IS NULL FROM logical_port AS l INNER JOIN appliance_physical_port AS p ON l.physical_port = p.id INNER JOIN appliance AS a ON a.id = p.appliance INNER JOIN source AS s ON s.logical_port = l.id LEFT JOIN input AS i ON i.id = s.input WHERE a.id = 'a64eda8d-5114-4f75-9ac2-8b8ff0002bd9' | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.038056+00:00 | 00:00:00.000199 | executing: SELECT l.id IS NULL, p.port_index IS NULL, a.type IS NULL, s.stream IS NULL, i.channel_id IS NULL FROM logical_port AS l INNER JOIN appliance_physical_port AS p ON l.physical_port = p.id INNER JOIN appliance AS a ON a.id = p.appliance INNER JOIN source AS s ON s.logical_port = l.id LEFT JOIN input AS i ON i.id = s.input WHERE a.id = 'a64eda8d-5114-4f75-9ac2-8b8ff0002bd9' in state: Open | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.038069+00:00 | 00:00:00.000212 | planning starts: SELECT | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.03808+00:00 | 00:00:00.000223 | query cache miss | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.038164+00:00 | 00:00:00.000307 | added table 'defaultdb.public.logical_port' to table collection | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.03824+00:00 | 00:00:00.000383 | added table 'defaultdb.public.appliance_physical_port' to table collection | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.038945+00:00 | 00:00:00.001088 | added table 'defaultdb.public.appliance' to table collection | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.039147+00:00 | 00:00:00.00129 | added table 'defaultdb.public.source' to table collection | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.039306+00:00 | 00:00:00.001449 | added table 'defaultdb.public.input' to table collection | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.043692+00:00 | 00:00:00.005835 | query cache add | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.043859+00:00 | 00:00:00.006002 | planning ends | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.043869+00:00 | 00:00:00.006012 | checking distributability | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.043879+00:00 | 00:00:00.006022 | will distribute plan: true | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.043883+00:00 | 00:00:00.006026 | execution starts: distributed engine | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.043885+00:00 | 00:00:00.006028 | === SPAN START: consuming rows === | | | consuming rows | 4
2020-07-08 18:33:02.043899+00:00 | 00:00:00.006042 | creating DistSQL plan with isLocal=false | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.043939+00:00 | 00:00:00.006082 | querying next range at /Table/58/1 | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.043981+00:00 | 00:00:00.006124 | querying next range at /Table/56/2 | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.044023+00:00 | 00:00:00.006166 | querying next range at /Table/53/2/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9" | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.044069+00:00 | 00:00:00.006212 | querying next range at /Table/52/1/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9" | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.044112+00:00 | 00:00:00.006255 | querying next range at /Table/55/5 | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.04419+00:00 | 00:00:00.006333 | running DistSQL plan | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.044231+00:00 | 00:00:00.006375 | === SPAN START: /cockroach.sql.distsqlrun.DistSQL/SetupFlow === | | | /cockroach.sql.distsqlrun.DistSQL/SetupFlow | 5
2020-07-08 18:33:02.044262+00:00 | 00:00:00.006405 | === SPAN START: /cockroach.sql.distsqlrun.DistSQL/SetupFlow === | | | /cockroach.sql.distsqlrun.DistSQL/SetupFlow | 6
2020-07-08 18:33:02.045239+00:00 | 00:00:00.007382 | === SPAN START: outbox === | | | outbox | 7
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 347 B | | | |
| | cockroach.streamid: 26 | | | |
2020-07-08 18:33:02.045242+00:00 | 00:00:00.007385 | === SPAN START: outbox === | | | outbox | 8
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 3.0 KiB | | | |
| | cockroach.streamid: 22 | | | |
2020-07-08 18:33:02.045277+00:00 | 00:00:00.00742 | === SPAN START: [async] drain === | | | [async] drain | 9
2020-07-08 18:33:02.045307+00:00 | 00:00:00.00745 | === SPAN START: [async] drain === | | | [async] drain | 10
2020-07-08 18:33:02.045308+00:00 | 00:00:00.007451 | === SPAN START: router output === | | | router output | 11
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 2 | | | |
| | cockroach.streamid: 9 | | | |
2020-07-08 18:33:02.04532+00:00 | 00:00:00.007463 | === SPAN START: router output === | | | router output | 12
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 1 | | | |
| | cockroach.streamid: 4 | | | |
2020-07-08 18:33:02.045325+00:00 | 00:00:00.007468 | === SPAN START: outbox === | | | outbox | 13
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 1.9 KiB | | | |
| | cockroach.streamid: 6 | | | |
2020-07-08 18:33:02.045336+00:00 | 00:00:00.007479 | === SPAN START: router output === | | | router output | 14
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 16 | | | |
2020-07-08 18:33:02.045341+00:00 | 00:00:00.007484 | === SPAN START: router output === | | | router output | 15
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 22 | | | |
2020-07-08 18:33:02.045341+00:00 | 00:00:00.007484 | === SPAN START: outbox === | | | outbox | 16
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 5.4 KiB | | | |
| | cockroach.streamid: 2 | | | |
2020-07-08 18:33:02.045349+00:00 | 00:00:00.007492 | === SPAN START: router output === | | | router output | 17
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 26 | | | |
2020-07-08 18:33:02.04535+00:00 | 00:00:00.007493 | === SPAN START: outbox === | | | outbox | 18
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 2.6 KiB | | | |
| | cockroach.streamid: 13 | | | |
2020-07-08 18:33:02.045352+00:00 | 00:00:00.007495 | === SPAN START: hash joiner === | | | hash joiner | 19
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.processorid: 11 | | | |
| | cockroach.stat.hashjoiner.disk.max: 0 B | | | |
| | cockroach.stat.hashjoiner.left.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.left.stalltime: 0s | | | |
| | cockroach.stat.hashjoiner.mem.max: 0 B | | | |
| | cockroach.stat.hashjoiner.right.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.right.stalltime: 1.869ms | | | |
| | cockroach.stat.hashjoiner.stored_side: left | | | |
2020-07-08 18:33:02.045363+00:00 | 00:00:00.007506 | === SPAN START: merge joiner === | | | merge joiner | 20
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.processorid: 8 | | | |
| | cockroach.stat.mergejoiner.left.input.rows: 3 | | | |
| | cockroach.stat.mergejoiner.left.stalltime: 1.794ms | | | |
| | cockroach.stat.mergejoiner.mem.max: 10 KiB | | | |
| | cockroach.stat.mergejoiner.right.input.rows: 0 | | | |
| | cockroach.stat.mergejoiner.right.stalltime: 1µs | | | |
2020-07-08 18:33:02.045364+00:00 | 00:00:00.007507 | === SPAN START: hash joiner === | | | hash joiner | 21
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.processorid: 15 | | | |
| | cockroach.stat.hashjoiner.disk.max: 0 B | | | |
| | cockroach.stat.hashjoiner.left.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.left.stalltime: 0s | | | |
| | cockroach.stat.hashjoiner.mem.max: 0 B | | | |
| | cockroach.stat.hashjoiner.right.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.right.stalltime: 1.129ms | | | |
| | cockroach.stat.hashjoiner.stored_side: left | | | |
2020-07-08 18:33:02.045375+00:00 | 00:00:00.007518 | === SPAN START: [async] drain === | | | [async] drain | 22
2020-07-08 18:33:02.045381+00:00 | 00:00:00.007524 | === SPAN START: router output === | | | router output | 23
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 6 | | | |
2020-07-08 18:33:02.045387+00:00 | 00:00:00.00753 | === SPAN START: router output === | | | router output | 24
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 30 | | | |
2020-07-08 18:33:02.045391+00:00 | 00:00:00.007534 | === SPAN START: merge joiner === | | | merge joiner | 25
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.processorid: 5 | | | |
| | cockroach.stat.mergejoiner.left.input.rows: 5 | | | |
| | cockroach.stat.mergejoiner.left.stalltime: 1.102ms | | | |
| | cockroach.stat.mergejoiner.mem.max: 20 KiB | | | |
| | cockroach.stat.mergejoiner.right.input.rows: 1 | | | |
| | cockroach.stat.mergejoiner.right.stalltime: 1µs | | | |
2020-07-08 18:33:02.045394+00:00 | 00:00:00.007537 | === SPAN START: [async] drain === | | | [async] drain | 26
2020-07-08 18:33:02.045398+00:00 | 00:00:00.007541 | === SPAN START: table reader === | | | table reader | 27
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.processorid: 2 | | | |
| | cockroach.stat.tablereader.bytes.read: 130 B | | | |
| | cockroach.stat.tablereader.input.rows: 2 | | | |
| | cockroach.stat.tablereader.stalltime: 488µs | | | |
2020-07-08 18:33:02.045407+00:00 | 00:00:00.00755 | === SPAN START: outbox === | | | outbox | 28
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 3.4 KiB | | | |
| | cockroach.streamid: 34 | | | |
2020-07-08 18:33:02.045411+00:00 | 00:00:00.007554 | starting scan with limitBatches true | [n2] | | table reader | 27
2020-07-08 18:33:02.045412+00:00 | 00:00:00.007555 | === SPAN START: router output === | | | router output | 29
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 19 | | | |
2020-07-08 18:33:02.045415+00:00 | 00:00:00.007558 | === SPAN START: [async] drain === | | | [async] drain | 30
2020-07-08 18:33:02.045429+00:00 | 00:00:00.007572 | === SPAN START: router output === | | | router output | 31
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 1 | | | |
| | cockroach.streamid: 2 | | | |
2020-07-08 18:33:02.045445+00:00 | 00:00:00.007588 | === SPAN START: outbox === | | | outbox | 33
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 347 B | | | |
| | cockroach.streamid: 16 | | | |
2020-07-08 18:33:02.045445+00:00 | 00:00:00.007588 | === SPAN START: router output === | | | router output | 32
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 13 | | | |
2020-07-08 18:33:02.045449+00:00 | 00:00:00.007592 | === SPAN START: [async] drain === | | | [async] drain | 34
2020-07-08 18:33:02.045469+00:00 | 00:00:00.007612 | Scan /Table/53/2/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9"{-/PrefixEnd} | [n2] | | table reader | 27
2020-07-08 18:33:02.045471+00:00 | 00:00:00.007615 | === SPAN START: outbox === | | | outbox | 35
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 347 B | | | |
| | cockroach.streamid: 29 | | | |
2020-07-08 18:33:02.045473+00:00 | 00:00:00.007616 | === SPAN START: txn coordinator send === | | | txn coordinator send | 36
2020-07-08 18:33:02.045476+00:00 | 00:00:00.007619 | === SPAN START: [async] drain === | | | [async] drain | 37
2020-07-08 18:33:02.045499+00:00 | 00:00:00.007642 | === SPAN START: dist sender send === | | | dist sender send | 38
2020-07-08 18:33:02.045502+00:00 | 00:00:00.007645 | === SPAN START: router output === | | | router output | 39
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 21 | | | |
2020-07-08 18:33:02.045512+00:00 | 00:00:00.007655 | === SPAN START: router output === | | | router output | 40
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 25 | | | |
2020-07-08 18:33:02.045514+00:00 | 00:00:00.007657 | querying next range at /Table/53/2/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9" | [n2,txn=d35568dd] | | dist sender send | 38
2020-07-08 18:33:02.045523+00:00 | 00:00:00.007666 | === SPAN START: router output === | | | router output | 41
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 29 | | | |
2020-07-08 18:33:02.045531+00:00 | 00:00:00.007674 | === SPAN START: [async] drain === | | | [async] drain | 42
2020-07-08 18:33:02.045531+00:00 | 00:00:00.007674 | === SPAN START: outbox === | | | outbox | 43
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 2.4 KiB | | | |
| | cockroach.streamid: 23 | | | |
2020-07-08 18:33:02.045582+00:00 | 00:00:00.007725 | === SPAN START: [async] drain === | | | [async] drain | 44
2020-07-08 18:33:02.045583+00:00 | 00:00:00.007726 | === SPAN START: outbox === | | | outbox | 45
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 581 B | | | |
| | cockroach.streamid: 3 | | | |
2020-07-08 18:33:02.045599+00:00 | 00:00:00.007742 | r34: sending batch 1 Scan to (n2,s2):3 | [n2,txn=d35568dd] | | dist sender send | 38
2020-07-08 18:33:02.045602+00:00 | 00:00:00.007745 | === SPAN START: table reader === | | | table reader | 46
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.processorid: 6 | | | |
| | cockroach.stat.tablereader.bytes.read: 0 B | | | |
| | cockroach.stat.tablereader.input.rows: 0 | | | |
| | cockroach.stat.tablereader.stalltime: 410µs | | | |
2020-07-08 18:33:02.045603+00:00 | 00:00:00.007746 | sending request to local client | [n2,txn=d35568dd] | | dist sender send | 38
2020-07-08 18:33:02.045606+00:00 | 00:00:00.007749 | === SPAN START: hash joiner === | | | hash joiner | 47
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.processorid: 14 | | | |
| | cockroach.stat.hashjoiner.disk.max: 0 B | | | |
| | cockroach.stat.hashjoiner.left.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.left.stalltime: 2.045ms | | | |
| | cockroach.stat.hashjoiner.mem.max: 10 KiB | | | |
| | cockroach.stat.hashjoiner.right.input.rows: 1 | | | |
| | cockroach.stat.hashjoiner.right.stalltime: 475µs | | | |
| | cockroach.stat.hashjoiner.stored_side: left | | | |
2020-07-08 18:33:02.045608+00:00 | 00:00:00.007751 | === SPAN START: /cockroach.roachpb.Internal/Batch === | | | /cockroach.roachpb.Internal/Batch | 48
2020-07-08 18:33:02.045609+00:00 | 00:00:00.007752 | === SPAN START: [async] drain === | | | [async] drain | 49
2020-07-08 18:33:02.045612+00:00 | 00:00:00.007755 | node received request: 1 Scan | [n2] | | /cockroach.roachpb.Internal/Batch | 48
2020-07-08 18:33:02.045627+00:00 | 00:00:00.00777 | === SPAN START: hash joiner === | | | hash joiner | 50
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.processorid: 10 | | | |
| | cockroach.stat.hashjoiner.disk.max: 0 B | | | |
| | cockroach.stat.hashjoiner.left.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.left.stalltime: 0s | | | |
| | cockroach.stat.hashjoiner.mem.max: 0 B | | | |
| | cockroach.stat.hashjoiner.right.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.right.stalltime: 1.851ms | | | |
| | cockroach.stat.hashjoiner.stored_side: left | | | |
2020-07-08 18:33:02.045629+00:00 | 00:00:00.007772 | starting scan with limitBatches false | [n1] | | table reader | 46
2020-07-08 18:33:02.045633+00:00 | 00:00:00.007776 | === SPAN START: table reader === | | | table reader | 51
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.processorid: 12 | | | |
| | cockroach.stat.tablereader.bytes.read: 162 B | | | |
| | cockroach.stat.tablereader.input.rows: 1 | | | |
| | cockroach.stat.tablereader.stalltime: 345µs | | | |
2020-07-08 18:33:02.045649+00:00 | 00:00:00.007792 | starting scan with limitBatches true | [n1] | | table reader | 51
2020-07-08 18:33:02.04565+00:00 | 00:00:00.007793 | === SPAN START: merge joiner === | | | merge joiner | 52
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.processorid: 7 | | | |
| | cockroach.stat.mergejoiner.left.input.rows: 0 | | | |
| | cockroach.stat.mergejoiner.left.stalltime: 1.206ms | | | |
| | cockroach.stat.mergejoiner.mem.max: 0 B | | | |
| | cockroach.stat.mergejoiner.right.input.rows: 0 | | | |
| | cockroach.stat.mergejoiner.right.stalltime: 0s | | | |
2020-07-08 18:33:02.045656+00:00 | 00:00:00.007799 | === SPAN START: flow === | | | flow | 53
2020-07-08 18:33:02.045657+00:00 | 00:00:00.0078 | === SPAN START: outbox === | | | outbox | 54
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 17 KiB | | | |
| | cockroach.streamid: 12 | | | |
2020-07-08 18:33:02.045659+00:00 | 00:00:00.007802 | Scan /Table/52/1/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9"{-/#} | [n1] | | table reader | 46
2020-07-08 18:33:02.045664+00:00 | 00:00:00.007807 | === SPAN START: txn coordinator send === | | | txn coordinator send | 55
2020-07-08 18:33:02.045667+00:00 | 00:00:00.00781 | Scan /Table/55/{5-6} | [n1] | | table reader | 51
2020-07-08 18:33:02.04567+00:00 | 00:00:00.007813 | === SPAN START: outbox === | | | outbox | 56
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 347 B | | | |
| | cockroach.streamid: 18 | | | |
2020-07-08 18:33:02.045671+00:00 | 00:00:00.007814 | executing [txn: d35568dd], Scan [/Table/53/2/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9",/Table/53/2/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9"/PrefixEnd) | [n2,s2] | | /cockroach.roachpb.Internal/Batch | 48
2020-07-08 18:33:02.045675+00:00 | 00:00:00.007818 | === SPAN START: txn coordinator send === | | | txn coordinator send | 57
2020-07-08 18:33:02.045677+00:00 | 00:00:00.00782 | === SPAN START: router output === | | | router output | 59
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 5 | | | |
| | cockroach.streamid: 3 | | | |
2020-07-08 18:33:02.045677+00:00 | 00:00:00.00782 | === SPAN START: router output === | | | router output | 58
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 5 | | | |
2020-07-08 18:33:02.045682+00:00 | 00:00:00.007825 | read-only path | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 48
2020-07-08 18:33:02.045683+00:00 | 00:00:00.007826 | === SPAN START: router output === | | | router output | 60
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 12 | | | |
| | cockroach.streamid: 1 | | | |
2020-07-08 18:33:02.045689+00:00 | 00:00:00.007832 | === SPAN START: outbox === | | | outbox | 61
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 523 B | | | |
| | cockroach.streamid: 8 | | | |
2020-07-08 18:33:02.045692+00:00 | 00:00:00.007835 | === SPAN START: outbox === | | | outbox | 62
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 3.0 KiB | | | |
| | cockroach.streamid: 21 | | | |
2020-07-08 18:33:02.045692+00:00 | 00:00:00.007835 | === SPAN START: [async] drain === | | | [async] drain | 63
2020-07-08 18:33:02.045695+00:00 | 00:00:00.007838 | === SPAN START: dist sender send === | | | dist sender send | 64
2020-07-08 18:33:02.045703+00:00 | 00:00:00.007846 | sequencing request | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 48
2020-07-08 18:33:02.045705+00:00 | 00:00:00.007848 | === SPAN START: dist sender send === | | | dist sender send | 65
2020-07-08 18:33:02.045706+00:00 | 00:00:00.007849 | acquiring latches | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 48
2020-07-08 18:33:02.045707+00:00 | 00:00:00.00785 | === SPAN START: [async] drain === | | | [async] drain | 66
2020-07-08 18:33:02.04571+00:00 | 00:00:00.007853 | querying next range at /Table/52/1/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9" | [n1,txn=d35568dd] | | dist sender send | 64
2020-07-08 18:33:02.045715+00:00 | 00:00:00.007858 | scanning lock table for conflicting locks | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 48
2020-07-08 18:33:02.045719+00:00 | 00:00:00.007862 | querying next range at /Table/55/5 | [n1,txn=d35568dd] | | dist sender send | 65
2020-07-08 18:33:02.045722+00:00 | 00:00:00.007865 | waiting for read lock | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 48
2020-07-08 18:33:02.04574+00:00 | 00:00:00.007883 | === SPAN START: [async] drain === | | | [async] drain | 67
2020-07-08 18:33:02.045749+00:00 | 00:00:00.007892 | === SPAN START: router output === | | | router output | 68
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 1 | | | |
| | cockroach.streamid: 8 | | | |
2020-07-08 18:33:02.045754+00:00 | 00:00:00.007897 | === SPAN START: [async] drain === | | | [async] drain | 69
2020-07-08 18:33:02.045758+00:00 | 00:00:00.007901 | === SPAN START: outbox === | | | outbox | 70
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 347 B | | | |
| | cockroach.streamid: 10 | | | |
2020-07-08 18:33:02.045761+00:00 | 00:00:00.007905 | === SPAN START: router output === | | | router output | 71
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 15 | | | |
2020-07-08 18:33:02.045763+00:00 | 00:00:00.007906 | === SPAN START: router output === | | | router output | 72
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 18 | | | |
2020-07-08 18:33:02.045772+00:00 | 00:00:00.007915 | === SPAN START: router output === | | | router output | 73
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 12 | | | |
2020-07-08 18:33:02.045779+00:00 | 00:00:00.007922 | === SPAN START: router output === | | | router output | 74
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 10 | | | |
2020-07-08 18:33:02.045781+00:00 | 00:00:00.007924 | === SPAN START: router output === | | | router output | 75
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 7 | | | |
2020-07-08 18:33:02.045788+00:00 | 00:00:00.007931 | === SPAN START: router output === | | | router output | 77
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 31 | | | |
2020-07-08 18:33:02.045788+00:00 | 00:00:00.007931 | === SPAN START: router output === | | | router output | 76
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 23 | | | |
2020-07-08 18:33:02.045795+00:00 | 00:00:00.007938 | === SPAN START: router output === | | | router output | 78
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 1 | | | |
| | cockroach.streamid: 27 | | | |
2020-07-08 18:33:02.045795+00:00 | 00:00:00.007938 | === SPAN START: outbox === | | | outbox | 79
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 347 B | | | |
| | cockroach.streamid: 31 | | | |
2020-07-08 18:33:02.045798+00:00 | 00:00:00.007941 | === SPAN START: [async] drain === | | | [async] drain | 80
2020-07-08 18:33:02.045798+00:00 | 00:00:00.007941 | r36: sending batch 1 Scan to (n1,s1):1 | [n1,txn=d35568dd] | | dist sender send | 65
2020-07-08 18:33:02.0458+00:00 | 00:00:00.007943 | === SPAN START: table reader === | | | table reader | 81
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.processorid: 1 | | | |
| | cockroach.stat.tablereader.bytes.read: 1.1 KiB | | | |
| | cockroach.stat.tablereader.input.rows: 17 | | | |
| | cockroach.stat.tablereader.stalltime: 341µs | | | |
2020-07-08 18:33:02.045802+00:00 | 00:00:00.007945 | sending request to local client | [n1,txn=d35568dd] | | dist sender send | 65
2020-07-08 18:33:02.045802+00:00 | 00:00:00.007945 | r33: sending batch 1 Scan to (n1,s1):1 | [n1,txn=d35568dd] | | dist sender send | 64
2020-07-08 18:33:02.045805+00:00 | 00:00:00.007948 | === SPAN START: outbox === | | | outbox | 82
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 3.0 KiB | | | |
| | cockroach.streamid: 33 | | | |
2020-07-08 18:33:02.045806+00:00 | 00:00:00.007949 | sending request to local client | [n1,txn=d35568dd] | | dist sender send | 64
2020-07-08 18:33:02.045806+00:00 | 00:00:00.00795 | === SPAN START: /cockroach.roachpb.Internal/Batch === | | | /cockroach.roachpb.Internal/Batch | 83
2020-07-08 18:33:02.04581+00:00 | 00:00:00.007953 | === SPAN START: /cockroach.roachpb.Internal/Batch === | | | /cockroach.roachpb.Internal/Batch | 84
2020-07-08 18:33:02.045812+00:00 | 00:00:00.007955 | node received request: 1 Scan | [n1] | | /cockroach.roachpb.Internal/Batch | 83
2020-07-08 18:33:02.045815+00:00 | 00:00:00.007958 | node received request: 1 Scan | [n1] | | /cockroach.roachpb.Internal/Batch | 84
2020-07-08 18:33:02.045819+00:00 | 00:00:00.007962 | starting scan with limitBatches true | [n1] | | table reader | 81
2020-07-08 18:33:02.045821+00:00 | 00:00:00.007964 | read completed | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 48
2020-07-08 18:33:02.045834+00:00 | 00:00:00.007977 | executing [txn: d35568dd], Scan [/Table/55/5,/Table/55/6) | [n1,s1] | | /cockroach.roachpb.Internal/Batch | 83
2020-07-08 18:33:02.045838+00:00 | 00:00:00.007981 | Scan /Table/56/{2-3} | [n1] | | table reader | 81
2020-07-08 18:33:02.04584+00:00 | 00:00:00.007983 | executing [txn: d35568dd], Scan [/Table/52/1/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9",/Table/52/1/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9"/#) | [n1,s1] | | /cockroach.roachpb.Internal/Batch | 84
2020-07-08 18:33:02.045841+00:00 | 00:00:00.007984 | === SPAN START: txn coordinator send === | | | txn coordinator send | 85
2020-07-08 18:33:02.045843+00:00 | 00:00:00.007986 | read-only path | [n1,s1,r36/1:/Table/5{5-6}] | | /cockroach.roachpb.Internal/Batch | 83
2020-07-08 18:33:02.045848+00:00 | 00:00:00.007992 | read-only path | [n1,s1,r33/1:/Table/5{2-3}] | | /cockroach.roachpb.Internal/Batch | 84
2020-07-08 18:33:02.045849+00:00 | 00:00:00.007992 | === SPAN START: [async] drain === | | | [async] drain | 86
2020-07-08 18:33:02.045849+00:00 | 00:00:00.007992 | Consumer sent handshake. Consuming flow scheduled: true | [n2] | | [async] drain | 30
2020-07-08 18:33:02.045859+00:00 | 00:00:00.008002 | === SPAN START: [async] drain === | | | [async] drain | 87
2020-07-08 18:33:02.045858+00:00 | 00:00:00.008002 | sequencing request | [n1,s1,r36/1:/Table/5{5-6}] | | /cockroach.roachpb.Internal/Batch | 83
2020-07-08 18:33:02.045861+00:00 | 00:00:00.008004 | acquiring latches | [n1,s1,r36/1:/Table/5{5-6}] | | /cockroach.roachpb.Internal/Batch | 83
2020-07-08 18:33:02.045861+00:00 | 00:00:00.008004 | Consumer sent handshake. Consuming flow scheduled: true | [n2] | | [async] drain | 37
2020-07-08 18:33:02.045866+00:00 | 00:00:00.008009 | === SPAN START: dist sender send === | | | dist sender send | 88
2020-07-08 18:33:02.045868+00:00 | 00:00:00.008012 | sequencing request | [n1,s1,r33/1:/Table/5{2-3}] | | /cockroach.roachpb.Internal/Batch | 84
2020-07-08 18:33:02.04587+00:00 | 00:00:00.008013 | scanning lock table for conflicting locks | [n1,s1,r36/1:/Table/5{5-6}] | | /cockroach.roachpb.Internal/Batch | 83
2020-07-08 18:33:02.045871+00:00 | 00:00:00.008014 | Consumer sent handshake. Consuming flow scheduled: true | [n2] | | [async] drain | 22
2020-07-08 18:33:02.045871+00:00 | 00:00:00.008014 | acquiring latches | [n1,s1,r33/1:/Table/5{2-3}] | | /cockroach.roachpb.Internal/Batch | 84
2020-07-08 18:33:02.045875+00:00 | 00:00:00.008018 | waiting for read lock | [n1,s1,r36/1:/Table/5{5-6}] | | /cockroach.roachpb.Internal/Batch | 83
2020-07-08 18:33:02.045876+00:00 | 00:00:00.00802 | querying next range at /Table/56/2 | [n1,txn=d35568dd] | | dist sender send | 88
2020-07-08 18:33:02.045881+00:00 | 00:00:00.008024 | scanning lock table for conflicting locks | [n1,s1,r33/1:/Table/5{2-3}] | | /cockroach.roachpb.Internal/Batch | 84
2020-07-08 18:33:02.045884+00:00 | 00:00:00.008027 | Consumer sent handshake. Consuming flow scheduled: true | [n2] | | [async] drain | 9
2020-07-08 18:33:02.045886+00:00 | 00:00:00.008029 | waiting for read lock | [n1,s1,r33/1:/Table/5{2-3}] | | /cockroach.roachpb.Internal/Batch | 84
2020-07-08 18:33:02.045887+00:00 | 00:00:00.00803 | recording span to refresh: /Table/53/2/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9"{-/PrefixEnd} | [n2,txn=d35568dd] | | txn coordinator send | 36
2020-07-08 18:33:02.045891+00:00 | 00:00:00.008034 | === SPAN START: merge joiner === | | | merge joiner | 89
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.processorid: 4 | | | |
| | cockroach.stat.mergejoiner.left.input.rows: 12 | | | |
| | cockroach.stat.mergejoiner.left.stalltime: 272µs | | | |
| | cockroach.stat.mergejoiner.mem.max: 20 KiB | | | |
| | cockroach.stat.mergejoiner.right.input.rows: 1 | | | |
| | cockroach.stat.mergejoiner.right.stalltime: 589µs | | | |
2020-07-08 18:33:02.045897+00:00 | 00:00:00.00804 | === SPAN START: index joiner === | | | index joiner | 90
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.processorid: 3 | | | |
| | cockroach.stat.joinreader.index.input.rows: 2 | | | |
| | cockroach.stat.joinreader.index.stalltime: 295µs | | | |
| | cockroach.stat.joinreader.input.rows: 2 | | | |
| | cockroach.stat.joinreader.stalltime: 68µs | | | |
2020-07-08 18:33:02.045898+00:00 | 00:00:00.008041 | starting (3 processors, 6 startables) | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | flow | 53
2020-07-08 18:33:02.045916+00:00 | 00:00:00.008059 | === SPAN START: noop === | | | noop | 91
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.processorid: 16 | | | |
2020-07-08 18:33:02.045932+00:00 | 00:00:00.008075 | === SPAN START: hash joiner === | | | hash joiner | 92
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.processorid: 13 | | | |
| | cockroach.stat.hashjoiner.disk.max: 0 B | | | |
| | cockroach.stat.hashjoiner.left.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.left.stalltime: 0s | | | |
| | cockroach.stat.hashjoiner.mem.max: 0 B | | | |
| | cockroach.stat.hashjoiner.right.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.right.stalltime: 641µs | | | |
| | cockroach.stat.hashjoiner.stored_side: left | | | |
2020-07-08 18:33:02.045936+00:00 | 00:00:00.008079 | === SPAN START: router output === | | | router output | 93
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 20 | | | |
2020-07-08 18:33:02.045945+00:00 | 00:00:00.008088 | === SPAN START: router output === | | | router output | 94
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 24 | | | |
2020-07-08 18:33:02.045946+00:00 | 00:00:00.008089 | Consumer sent handshake. Consuming flow scheduled: false | [n2] | | [async] drain | 26
2020-07-08 18:33:02.045949+00:00 | 00:00:00.008092 | === SPAN START: router output === | | | router output | 95
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 4 | | | |
| | cockroach.streamid: 17 | | | |
2020-07-08 18:33:02.045955+00:00 | 00:00:00.008098 | === SPAN START: router output === | | | router output | 96
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 28 | | | |
2020-07-08 18:33:02.045955+00:00 | 00:00:00.008098 | read completed | [n1,s1,r36/1:/Table/5{5-6}] | | /cockroach.roachpb.Internal/Batch | 83
2020-07-08 18:33:02.045957+00:00 | 00:00:00.0081 | Consumer sent handshake. Consuming flow scheduled: false | [n2] | | [async] drain | 34
2020-07-08 18:33:02.045957+00:00 | 00:00:00.0081 | r37: sending batch 1 Scan to (n1,s1):1 | [n1,txn=d35568dd] | | dist sender send | 88
2020-07-08 18:33:02.045961+00:00 | 00:00:00.008104 | === SPAN START: outbox === | | | outbox | 97
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 404 B | | | |
| | cockroach.streamid: 24 | | | |
2020-07-08 18:33:02.045962+00:00 | 00:00:00.008105 | sending request to local client | [n1,txn=d35568dd] | | dist sender send | 88
2020-07-08 18:33:02.045964+00:00 | 00:00:00.008107 | === SPAN START: table reader === | | | table reader | 98
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.processorid: 0 | | | |
| | cockroach.stat.tablereader.bytes.read: 588 B | | | |
| | cockroach.stat.tablereader.input.rows: 5 | | | |
| | cockroach.stat.tablereader.stalltime: 368µs | | | |
2020-07-08 18:33:02.045965+00:00 | 00:00:00.008108 | === SPAN START: /cockroach.roachpb.Internal/Batch === | | | /cockroach.roachpb.Internal/Batch | 99
2020-07-08 18:33:02.045966+00:00 | 00:00:00.008109 | Consumer sent handshake. Consuming flow scheduled: false | [n2] | | [async] drain | 10
2020-07-08 18:33:02.045968+00:00 | 00:00:00.008112 | === SPAN START: router output === | | | router output | 100
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 14 | | | |
2020-07-08 18:33:02.04597+00:00 | 00:00:00.008113 | node received request: 1 Scan | [n1] | | /cockroach.roachpb.Internal/Batch | 99
2020-07-08 18:33:02.04597+00:00 | 00:00:00.008113 | starting scan with limitBatches true | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | table reader | 98
2020-07-08 18:33:02.045983+00:00 | 00:00:00.008126 | recording span to refresh: /Table/55/{5-6} | [n1,txn=d35568dd] | | txn coordinator send | 57
2020-07-08 18:33:02.045989+00:00 | 00:00:00.008132 | ReadWithinUncertaintyIntervalError: read at time 1594233182.038000681,0 encountered previous write with future timestamp 1594233182.042224096,0 within uncertainty interval `t <= 1594233182.045820794,0`; observed timestamps: [{1 1594233182.045820794,0} {3 1594233182.038000681,0}] | [n1,s1,r33/1:/Table/5{2-3}] | | /cockroach.roachpb.Internal/Batch | 84
2020-07-08 18:33:02.04599+00:00 | 00:00:00.008133 | Scan /Table/58/{1-2} | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | table reader | 98
2020-07-08 18:33:02.04599+00:00 | 00:00:00.008133 | executing [txn: d35568dd], Scan [/Table/56/2,/Table/56/3) | [n1,s1] | | /cockroach.roachpb.Internal/Batch | 99
2020-07-08 18:33:02.045993+00:00 | 00:00:00.008136 | === SPAN START: txn coordinator send === | | | txn coordinator send | 101
2020-07-08 18:33:02.045998+00:00 | 00:00:00.008141 | Consumer sent handshake. Consuming flow scheduled: false | [n1] | | [async] drain | 44
2020-07-08 18:33:02.045999+00:00 | 00:00:00.008142 | read-only path | [n1,s1,r37/1:/Table/5{6-7}] | | /cockroach.roachpb.Internal/Batch | 99
2020-07-08 18:33:02.046+00:00 | 00:00:00.008143 | Scan /Table/53/1/"v?\x04*EkF\xe4\xa1*\x81E\x1de\"Q"{-/#}, /Table/53/1/"Ծ\x8a\xaeh{E\xe8\x83\xc98C\\\xa9eZ"{-/#} | [n2] | | index joiner | 90
2020-07-08 18:33:02.046+00:00 | 00:00:00.008143 | replica.Send got error: ReadWithinUncertaintyIntervalError: read at time 1594233182.038000681,0 encountered previous write with future timestamp 1594233182.042224096,0 within uncertainty interval `t <= 1594233182.045820794,0`; observed timestamps: [{1 1594233182.045820794,0} {3 1594233182.038000681,0}] | [n1,s1,r33/1:/Table/5{2-3}] | | /cockroach.roachpb.Internal/Batch | 84
2020-07-08 18:33:02.046003+00:00 | 00:00:00.008146 | === SPAN START: txn coordinator send === | | | txn coordinator send | 102
2020-07-08 18:33:02.046006+00:00 | 00:00:00.008149 | *roachpb.ReadWithinUncertaintyIntervalError | [n1] | | /cockroach.roachpb.Internal/Batch | 84
2020-07-08 18:33:02.04601+00:00 | 00:00:00.008153 | === SPAN START: dist sender send === | | | dist sender send | 103
2020-07-08 18:33:02.046011+00:00 | 00:00:00.008154 | === SPAN START: [async] drain === | | | [async] drain | 104
2020-07-08 18:33:02.046015+00:00 | 00:00:00.008158 | sequencing request | [n1,s1,r37/1:/Table/5{6-7}] | | /cockroach.roachpb.Internal/Batch | 99
2020-07-08 18:33:02.046015+00:00 | 00:00:00.008158 | === SPAN START: outbox === | | | outbox | 105
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 404 B | | | |
| | cockroach.streamid: 28 | | | |
2020-07-08 18:33:02.046018+00:00 | 00:00:00.008161 | acquiring latches | [n1,s1,r37/1:/Table/5{6-7}] | | /cockroach.roachpb.Internal/Batch | 99
2020-07-08 18:33:02.046019+00:00 | 00:00:00.008162 | === SPAN START: dist sender send === | | | dist sender send | 106
2020-07-08 18:33:02.046026+00:00 | 00:00:00.008169 | scanning lock table for conflicting locks | [n1,s1,r37/1:/Table/5{6-7}] | | /cockroach.roachpb.Internal/Batch | 99
2020-07-08 18:33:02.046027+00:00 | 00:00:00.00817 | querying next range at /Table/53/1/"v?\x04*EkF\xe4\xa1*\x81E\x1de\"Q" | [n2,txn=d35568dd] | | dist sender send | 103
2020-07-08 18:33:02.04603+00:00 | 00:00:00.008173 | querying next range at /Table/58/1 | [n3,client=172.18.0.4:40310,hostnossl,user=root,txn=d35568dd] | | dist sender send | 106
2020-07-08 18:33:02.04603+00:00 | 00:00:00.008173 | waiting for read lock | [n1,s1,r37/1:/Table/5{6-7}] | | /cockroach.roachpb.Internal/Batch | 99
2020-07-08 18:33:02.046032+00:00 | 00:00:00.008175 | reply error [txn: d35568dd], Scan [/Table/52/1/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9",/Table/52/1/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9"/#): ReadWithinUncertaintyIntervalError: read at time 1594233182.038000681,0 encountered previous write with future timestamp 1594233182.042224096,0 within uncertainty interval `t <= 1594233182.045820794,0`; observed timestamps: [{1 1594233182.045820794,0} {3 1594233182.038000681,0}] | [n1,txn=d35568dd] | | dist sender send | 64
2020-07-08 18:33:02.046043+00:00 | 00:00:00.008186 | === SPAN START: outbox === | | | outbox | 107
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 615 B | | | |
| | cockroach.streamid: 17 | | | |
2020-07-08 18:33:02.046053+00:00 | 00:00:00.008197 | === SPAN START: router output === | | | router output | 108
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 1 | | | |
| | cockroach.streamid: 11 | | | |
2020-07-08 18:33:02.046056+00:00 | 00:00:00.008199 | r34: sending batch 2 Scan to (n2,s2):3 | [n2,txn=d35568dd] | | dist sender send | 103
2020-07-08 18:33:02.046059+00:00 | 00:00:00.008202 | sending request to local client | [n2,txn=d35568dd] | | dist sender send | 103
2020-07-08 18:33:02.046061+00:00 | 00:00:00.008204 | === SPAN START: hash joiner === | | | hash joiner | 109
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.processorid: 9 | | | |
| | cockroach.stat.hashjoiner.disk.max: 0 B | | | |
| | cockroach.stat.hashjoiner.left.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.left.stalltime: 0s | | | |
| | cockroach.stat.hashjoiner.mem.max: 0 B | | | |
| | cockroach.stat.hashjoiner.right.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.right.stalltime: 1.771ms | | | |
| | cockroach.stat.hashjoiner.stored_side: left | | | |
2020-07-08 18:33:02.046062+00:00 | 00:00:00.008205 | === SPAN START: /cockroach.roachpb.Internal/Batch === | | | /cockroach.roachpb.Internal/Batch | 110
2020-07-08 18:33:02.046065+00:00 | 00:00:00.008208 | Consumer sent handshake. Consuming flow scheduled: true | [n1] | | [async] drain | 49
2020-07-08 18:33:02.046066+00:00 | 00:00:00.008209 | node received request: 2 Scan | [n2] | | /cockroach.roachpb.Internal/Batch | 110
2020-07-08 18:33:02.046072+00:00 | 00:00:00.008215 | Consumer sent handshake. Consuming flow scheduled: true | [n1] | | [async] drain | 66
2020-07-08 18:33:02.046075+00:00 | 00:00:00.008218 | === SPAN START: [async] drain === | | | [async] drain | 111
2020-07-08 18:33:02.046094+00:00 | 00:00:00.008237 | executing [txn: d35568dd], Scan [/Table/53/1/"v?\x04*EkF\xe4\xa1*\x81E\x1de\"Q",/Table/53/1/"v?\x04*EkF\xe4\xa1*\x81E\x1de\"Q"/#), Scan [/Table/53/1/"Ծ\x8a\xaeh{E\xe8\x83\xc98C\\\xa9eZ",/Table/53/1/"Ծ\x8a\xaeh{E\xe8\x83\xc98C\\\xa9eZ"/#) | [n2,s2] | | /cockroach.roachpb.Internal/Batch | 110
2020-07-08 18:33:02.046094+00:00 | 00:00:00.008237 | === SPAN START: [async] drain === | | | [async] drain | 112
2020-07-08 18:33:02.046099+00:00 | 00:00:00.008243 | === SPAN START: outbox === | | | outbox | 113
| | cockroach.flowid: 20d576a8-0045-423e-8183-b29435110b57 | | | |
| | cockroach.stat.outbox.bytes_sent: 404 B | | | |
| | cockroach.streamid: 14 | | | |
2020-07-08 18:33:02.046102+00:00 | 00:00:00.008245 | read-only path | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 110
2020-07-08 18:33:02.046105+00:00 | 00:00:00.008248 | Consumer sent handshake. Consuming flow scheduled: true | [n1] | | [async] drain | 44
2020-07-08 18:33:02.046108+00:00 | 00:00:00.008251 | r39: sending batch 1 Scan to (n3,s3):2 | [n3,client=172.18.0.4:40310,hostnossl,user=root,txn=d35568dd] | | dist sender send | 106
2020-07-08 18:33:02.046113+00:00 | 00:00:00.008256 | sending request to local client | [n3,client=172.18.0.4:40310,hostnossl,user=root,txn=d35568dd] | | dist sender send | 106
2020-07-08 18:33:02.046115+00:00 | 00:00:00.008258 | Consumer sent handshake. Consuming flow scheduled: true | [n1] | | [async] drain | 63
2020-07-08 18:33:02.046115+00:00 | 00:00:00.008258 | read completed | [n1,s1,r37/1:/Table/5{6-7}] | | /cockroach.roachpb.Internal/Batch | 99
2020-07-08 18:33:02.046117+00:00 | 00:00:00.00826 | === SPAN START: /cockroach.roachpb.Internal/Batch === | | | /cockroach.roachpb.Internal/Batch | 114
2020-07-08 18:33:02.046118+00:00 | 00:00:00.008261 | sequencing request | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 110
2020-07-08 18:33:02.04612+00:00 | 00:00:00.008263 | acquiring latches | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 110
2020-07-08 18:33:02.046121+00:00 | 00:00:00.008265 | node received request: 1 Scan | [n3] | | /cockroach.roachpb.Internal/Batch | 114
2020-07-08 18:33:02.046127+00:00 | 00:00:00.00827 | Consumer sent handshake. Consuming flow scheduled: true | [n2] | | [async] drain | 26
2020-07-08 18:33:02.046128+00:00 | 00:00:00.008271 | scanning lock table for conflicting locks | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 110
2020-07-08 18:33:02.046129+00:00 | 00:00:00.008272 | Consumer sent handshake. Consuming flow scheduled: true | [n2] | | [async] drain | 10
2020-07-08 18:33:02.046132+00:00 | 00:00:00.008275 | waiting for read lock | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 110
2020-07-08 18:33:02.046134+00:00 | 00:00:00.008277 | === SPAN START: [async] drain === | | | [async] drain | 115
2020-07-08 18:33:02.04614+00:00 | 00:00:00.008283 | executing [txn: d35568dd], Scan [/Table/58/1,/Table/58/2) | [n3,s3] | | /cockroach.roachpb.Internal/Batch | 114
2020-07-08 18:33:02.046142+00:00 | 00:00:00.008286 | recording span to refresh: /Table/56/{2-3} | [n1,txn=d35568dd] | | txn coordinator send | 85
2020-07-08 18:33:02.046149+00:00 | 00:00:00.008292 | read-only path | [n3,s3,r39/2:/{Table/58-Max}] | | /cockroach.roachpb.Internal/Batch | 114
2020-07-08 18:33:02.046156+00:00 | 00:00:00.008299 | read has no clock uncertainty | [n3,s3,r39/2:/{Table/58-Max}] | | /cockroach.roachpb.Internal/Batch | 114
2020-07-08 18:33:02.046168+00:00 | 00:00:00.008311 | Consumer sent handshake. Consuming flow scheduled: true | [n1] | | [async] drain | 67
2020-07-08 18:33:02.046168+00:00 | 00:00:00.008311 | sequencing request | [n3,s3,r39/2:/{Table/58-Max}] | | /cockroach.roachpb.Internal/Batch | 114
2020-07-08 18:33:02.046171+00:00 | 00:00:00.008314 | acquiring latches | [n3,s3,r39/2:/{Table/58-Max}] | | /cockroach.roachpb.Internal/Batch | 114
2020-07-08 18:33:02.046172+00:00 | 00:00:00.008315 | Consumer sent handshake. Consuming flow scheduled: true | [n1] | | [async] drain | 42
2020-07-08 18:33:02.046178+00:00 | 00:00:00.008321 | scanning lock table for conflicting locks | [n3,s3,r39/2:/{Table/58-Max}] | | /cockroach.roachpb.Internal/Batch | 114
2020-07-08 18:33:02.046185+00:00 | 00:00:00.008328 | Consumer sent handshake. Consuming flow scheduled: true | [n2] | | [async] drain | 34
2020-07-08 18:33:02.046186+00:00 | 00:00:00.008329 | waiting for read lock | [n3,s3,r39/2:/{Table/58-Max}] | | /cockroach.roachpb.Internal/Batch | 114
2020-07-08 18:33:02.04622+00:00 | 00:00:00.008363 | read completed | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 110
2020-07-08 18:33:02.046242+00:00 | 00:00:00.008385 | Consumer sent handshake. Consuming flow scheduled: true | [n1] | | [async] drain | 69
2020-07-08 18:33:02.046248+00:00 | 00:00:00.008391 | recording span to refresh: /Table/53/1/"v?\x04*EkF\xe4\xa1*\x81E\x1de\"Q"{-/#} | [n2,txn=d35568dd] | | txn coordinator send | 102
2020-07-08 18:33:02.046251+00:00 | 00:00:00.008394 | Consumer sent handshake. Consuming flow scheduled: true | [n1] | | [async] drain | 87
2020-07-08 18:33:02.046262+00:00 | 00:00:00.008406 | recording span to refresh: /Table/53/1/"Ծ\x8a\xaeh{E\xe8\x83\xc98C\\\xa9eZ"{-/#} | [n2,txn=d35568dd] | | txn coordinator send | 102
2020-07-08 18:33:02.046289+00:00 | 00:00:00.008432 | read completed | [n3,s3,r39/2:/{Table/58-Max}] | | /cockroach.roachpb.Internal/Batch | 114
2020-07-08 18:33:02.046323+00:00 | 00:00:00.008466 | recording span to refresh: /Table/58/{1-2} | [n3,client=172.18.0.4:40310,hostnossl,user=root,txn=d35568dd] | | txn coordinator send | 101
2020-07-08 18:33:02.046383+00:00 | 00:00:00.008526 | Consumer sent handshake. Consuming flow scheduled: true | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | [async] drain | 111
2020-07-08 18:33:02.0464+00:00 | 00:00:00.008543 | Consumer sent handshake. Consuming flow scheduled: true | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | [async] drain | 112
2020-07-08 18:33:02.046433+00:00 | 00:00:00.008577 | Consumer sent handshake. Consuming flow scheduled: true | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | [async] drain | 115
2020-07-08 18:33:02.046457+00:00 | 00:00:00.0086 | Consumer sent handshake. Consuming flow scheduled: true | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | [async] drain | 104
2020-07-08 18:33:02.048633+00:00 | 00:00:00.010776 | execution ends | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.048635+00:00 | 00:00:00.010778 | rows affected: 0 | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.048662+00:00 | 00:00:00.010805 | AutoCommit. err: <nil> | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.048673+00:00 | 00:00:00.010816 | releasing 5 tables | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | session recording | 0
2020-07-08 18:33:02.048684+00:00 | 00:00:00.010827 | === SPAN START: exec stmt === | | | exec stmt | 116
2020-07-08 18:33:02.048694+00:00 | 00:00:00.010837 | [NoTxn pos:2] executing ExecStmt: SET TRACING = off | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 116
2020-07-08 18:33:02.048698+00:00 | 00:00:00.010841 | executing: SET TRACING = off in state: NoTxn | [n3,client=172.18.0.4:40310,hostnossl,user=root] | | exec stmt | 116
Raw
trace_2.txt
timestamp | age | message | tag | location | operation | span
-----------------------------------+-----------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------------------------------------------------+----------+---------------------------------------------+-------
2020-07-08 18:33:02.540586+00:00 | 00:00:00 | === SPAN START: session recording === | | | session recording | 0
2020-07-08 18:33:02.540598+00:00 | 00:00:00.000012 | === SPAN START: exec stmt === | | | exec stmt | 1
2020-07-08 18:33:02.540669+00:00 | 00:00:00.000083 | [NoTxn pos:1] executing ExecStmt: SELECT l.id IS NULL, p.port_index IS NULL, a.type IS NULL, s.stream IS NULL, i.channel_id IS NULL FROM logical_port AS l INNER JOIN appliance_physical_port AS p ON l.physical_port = p.id INNER JOIN appliance AS a ON a.id = p.appliance INNER JOIN source AS s ON s.logical_port = l.id LEFT JOIN input AS i ON i.id = s.input WHERE a.id = 'a64eda8d-5114-4f75-9ac2-8b8ff0002bd9' | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 1
2020-07-08 18:33:02.540683+00:00 | 00:00:00.000097 | executing: SELECT l.id IS NULL, p.port_index IS NULL, a.type IS NULL, s.stream IS NULL, i.channel_id IS NULL FROM logical_port AS l INNER JOIN appliance_physical_port AS p ON l.physical_port = p.id INNER JOIN appliance AS a ON a.id = p.appliance INNER JOIN source AS s ON s.logical_port = l.id LEFT JOIN input AS i ON i.id = s.input WHERE a.id = 'a64eda8d-5114-4f75-9ac2-8b8ff0002bd9' in state: NoTxn | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 1
2020-07-08 18:33:02.540691+00:00 | 00:00:00.000105 | === SPAN START: sql txn === | | | sql txn | 2
2020-07-08 18:33:02.540712+00:00 | 00:00:00.000126 | === SPAN START: exec stmt === | | | exec stmt | 3
2020-07-08 18:33:02.540727+00:00 | 00:00:00.000141 | [Open pos:1] executing ExecStmt: SELECT l.id IS NULL, p.port_index IS NULL, a.type IS NULL, s.stream IS NULL, i.channel_id IS NULL FROM logical_port AS l INNER JOIN appliance_physical_port AS p ON l.physical_port = p.id INNER JOIN appliance AS a ON a.id = p.appliance INNER JOIN source AS s ON s.logical_port = l.id LEFT JOIN input AS i ON i.id = s.input WHERE a.id = 'a64eda8d-5114-4f75-9ac2-8b8ff0002bd9' | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.540739+00:00 | 00:00:00.000153 | executing: SELECT l.id IS NULL, p.port_index IS NULL, a.type IS NULL, s.stream IS NULL, i.channel_id IS NULL FROM logical_port AS l INNER JOIN appliance_physical_port AS p ON l.physical_port = p.id INNER JOIN appliance AS a ON a.id = p.appliance INNER JOIN source AS s ON s.logical_port = l.id LEFT JOIN input AS i ON i.id = s.input WHERE a.id = 'a64eda8d-5114-4f75-9ac2-8b8ff0002bd9' in state: Open | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.540752+00:00 | 00:00:00.000166 | planning starts: SELECT | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.540759+00:00 | 00:00:00.000173 | query cache miss | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.540829+00:00 | 00:00:00.000243 | added table 'defaultdb.public.logical_port' to table collection | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.540889+00:00 | 00:00:00.000303 | added table 'defaultdb.public.appliance_physical_port' to table collection | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.541285+00:00 | 00:00:00.000699 | added table 'defaultdb.public.appliance' to table collection | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.54142+00:00 | 00:00:00.000834 | added table 'defaultdb.public.source' to table collection | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.541538+00:00 | 00:00:00.000952 | added table 'defaultdb.public.input' to table collection | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.544891+00:00 | 00:00:00.004305 | query cache add | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.545023+00:00 | 00:00:00.004437 | planning ends | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.545031+00:00 | 00:00:00.004445 | checking distributability | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.545037+00:00 | 00:00:00.004451 | will distribute plan: true | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.54504+00:00 | 00:00:00.004454 | execution starts: distributed engine | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.545042+00:00 | 00:00:00.004456 | === SPAN START: consuming rows === | | | consuming rows | 4
2020-07-08 18:33:02.545054+00:00 | 00:00:00.004468 | creating DistSQL plan with isLocal=false | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.545085+00:00 | 00:00:00.004499 | querying next range at /Table/58/1 | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.545121+00:00 | 00:00:00.004535 | querying next range at /Table/56/2 | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.545153+00:00 | 00:00:00.004567 | querying next range at /Table/53/2/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9" | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.545187+00:00 | 00:00:00.004601 | querying next range at /Table/52/1/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9" | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.545228+00:00 | 00:00:00.004642 | querying next range at /Table/55/5 | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.545288+00:00 | 00:00:00.004702 | running DistSQL plan | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.545322+00:00 | 00:00:00.004736 | === SPAN START: /cockroach.sql.distsqlrun.DistSQL/SetupFlow === | | | /cockroach.sql.distsqlrun.DistSQL/SetupFlow | 5
2020-07-08 18:33:02.545357+00:00 | 00:00:00.004771 | === SPAN START: /cockroach.sql.distsqlrun.DistSQL/SetupFlow === | | | /cockroach.sql.distsqlrun.DistSQL/SetupFlow | 6
2020-07-08 18:33:02.546519+00:00 | 00:00:00.005933 | === SPAN START: router output === | | | router output | 7
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 1 | | | |
| | cockroach.streamid: 4 | | | |
2020-07-08 18:33:02.546535+00:00 | 00:00:00.005949 | === SPAN START: outbox === | | | outbox | 8
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 5.4 KiB | | | |
| | cockroach.streamid: 2 | | | |
2020-07-08 18:33:02.546552+00:00 | 00:00:00.005966 | === SPAN START: outbox === | | | outbox | 9
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 1.8 KiB | | | |
| | cockroach.streamid: 6 | | | |
2020-07-08 18:33:02.546552+00:00 | 00:00:00.005966 | === SPAN START: router output === | | | router output | 10
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 1 | | | |
| | cockroach.streamid: 2 | | | |
2020-07-08 18:33:02.546572+00:00 | 00:00:00.005986 | === SPAN START: router output === | | | router output | 11
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 22 | | | |
2020-07-08 18:33:02.546579+00:00 | 00:00:00.005993 | === SPAN START: router output === | | | router output | 12
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 6 | | | |
2020-07-08 18:33:02.546582+00:00 | 00:00:00.005996 | === SPAN START: [async] drain === | | | [async] drain | 13
2020-07-08 18:33:02.546586+00:00 | 00:00:00.006 | === SPAN START: router output === | | | router output | 14
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 2 | | | |
| | cockroach.streamid: 9 | | | |
2020-07-08 18:33:02.546595+00:00 | 00:00:00.006009 | === SPAN START: [async] drain === | | | [async] drain | 15
2020-07-08 18:33:02.546595+00:00 | 00:00:00.006009 | === SPAN START: outbox === | | | outbox | 16
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 2.7 KiB | | | |
| | cockroach.streamid: 13 | | | |
2020-07-08 18:33:02.546636+00:00 | 00:00:00.00605 | === SPAN START: outbox === | | | outbox | 17
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 349 B | | | |
| | cockroach.streamid: 16 | | | |
2020-07-08 18:33:02.546641+00:00 | 00:00:00.006055 | === SPAN START: outbox === | | | outbox | 18
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 349 B | | | |
| | cockroach.streamid: 29 | | | |
2020-07-08 18:33:02.546642+00:00 | 00:00:00.006056 | === SPAN START: router output === | | | router output | 19
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 26 | | | |
2020-07-08 18:33:02.546646+00:00 | 00:00:00.00606 | === SPAN START: router output === | | | router output | 20
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 21 | | | |
2020-07-08 18:33:02.546647+00:00 | 00:00:00.006061 | === SPAN START: router output === | | | router output | 21
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 30 | | | |
2020-07-08 18:33:02.546649+00:00 | 00:00:00.006063 | === SPAN START: [async] drain === | | | [async] drain | 22
2020-07-08 18:33:02.546651+00:00 | 00:00:00.006065 | === SPAN START: router output === | | | router output | 23
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 25 | | | |
2020-07-08 18:33:02.546654+00:00 | 00:00:00.006068 | === SPAN START: router output === | | | router output | 24
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 16 | | | |
2020-07-08 18:33:02.546654+00:00 | 00:00:00.006068 | === SPAN START: outbox === | | | outbox | 25
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 3.5 KiB | | | |
| | cockroach.streamid: 34 | | | |
2020-07-08 18:33:02.546661+00:00 | 00:00:00.006075 | === SPAN START: [async] drain === | | | [async] drain | 26
2020-07-08 18:33:02.546662+00:00 | 00:00:00.006076 | === SPAN START: router output === | | | router output | 27
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 29 | | | |
2020-07-08 18:33:02.546668+00:00 | 00:00:00.006082 | === SPAN START: outbox === | | | outbox | 28
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 2.4 KiB | | | |
| | cockroach.streamid: 23 | | | |
2020-07-08 18:33:02.546669+00:00 | 00:00:00.006083 | === SPAN START: router output === | | | router output | 29
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 13 | | | |
2020-07-08 18:33:02.546679+00:00 | 00:00:00.006093 | === SPAN START: [async] drain === | | | [async] drain | 30
2020-07-08 18:33:02.546684+00:00 | 00:00:00.006098 | === SPAN START: outbox === | | | outbox | 31
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 349 B | | | |
| | cockroach.streamid: 26 | | | |
2020-07-08 18:33:02.54669+00:00 | 00:00:00.006104 | === SPAN START: router output === | | | router output | 32
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 19 | | | |
2020-07-08 18:33:02.546698+00:00 | 00:00:00.006112 | === SPAN START: merge joiner === | | | merge joiner | 33
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.processorid: 4 | | | |
| | cockroach.stat.mergejoiner.left.input.rows: 12 | | | |
| | cockroach.stat.mergejoiner.left.stalltime: 617µs | | | |
| | cockroach.stat.mergejoiner.mem.max: 20 KiB | | | |
| | cockroach.stat.mergejoiner.right.input.rows: 1 | | | |
| | cockroach.stat.mergejoiner.right.stalltime: 874µs | | | |
2020-07-08 18:33:02.546702+00:00 | 00:00:00.006116 | === SPAN START: router output === | | | router output | 34
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 7 | | | |
2020-07-08 18:33:02.546703+00:00 | 00:00:00.006117 | === SPAN START: hash joiner === | | | hash joiner | 35
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.processorid: 11 | | | |
| | cockroach.stat.hashjoiner.disk.max: 0 B | | | |
| | cockroach.stat.hashjoiner.left.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.left.stalltime: 0s | | | |
| | cockroach.stat.hashjoiner.mem.max: 0 B | | | |
| | cockroach.stat.hashjoiner.right.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.right.stalltime: 4.017ms | | | |
| | cockroach.stat.hashjoiner.stored_side: left | | | |
2020-07-08 18:33:02.546707+00:00 | 00:00:00.006121 | === SPAN START: [async] drain === | | | [async] drain | 36
2020-07-08 18:33:02.546708+00:00 | 00:00:00.006122 | === SPAN START: merge joiner === | | | merge joiner | 37
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.processorid: 5 | | | |
| | cockroach.stat.mergejoiner.left.input.rows: 5 | | | |
| | cockroach.stat.mergejoiner.left.stalltime: 922µs | | | |
| | cockroach.stat.mergejoiner.mem.max: 20 KiB | | | |
| | cockroach.stat.mergejoiner.right.input.rows: 1 | | | |
| | cockroach.stat.mergejoiner.right.stalltime: 1µs | | | |
2020-07-08 18:33:02.546715+00:00 | 00:00:00.006129 | === SPAN START: [async] drain === | | | [async] drain | 38
2020-07-08 18:33:02.546715+00:00 | 00:00:00.006129 | === SPAN START: hash joiner === | | | hash joiner | 39
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.processorid: 15 | | | |
| | cockroach.stat.hashjoiner.disk.max: 0 B | | | |
| | cockroach.stat.hashjoiner.left.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.left.stalltime: 0s | | | |
| | cockroach.stat.hashjoiner.mem.max: 0 B | | | |
| | cockroach.stat.hashjoiner.right.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.right.stalltime: 971µs | | | |
| | cockroach.stat.hashjoiner.stored_side: left | | | |
2020-07-08 18:33:02.546718+00:00 | 00:00:00.006132 | === SPAN START: table reader === | | | table reader | 40
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.processorid: 2 | | | |
| | cockroach.stat.tablereader.bytes.read: 130 B | | | |
| | cockroach.stat.tablereader.input.rows: 2 | | | |
| | cockroach.stat.tablereader.stalltime: 491µs | | | |
2020-07-08 18:33:02.546719+00:00 | 00:00:00.006133 | === SPAN START: merge joiner === | | | merge joiner | 41
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.processorid: 8 | | | |
| | cockroach.stat.mergejoiner.left.input.rows: 3 | | | |
| | cockroach.stat.mergejoiner.left.stalltime: 1.848ms | | | |
| | cockroach.stat.mergejoiner.mem.max: 10 KiB | | | |
| | cockroach.stat.mergejoiner.right.input.rows: 0 | | | |
| | cockroach.stat.mergejoiner.right.stalltime: 2.108ms | | | |
2020-07-08 18:33:02.54672+00:00 | 00:00:00.006134 | === SPAN START: outbox === | | | outbox | 42
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 582 B | | | |
| | cockroach.streamid: 3 | | | |
2020-07-08 18:33:02.546722+00:00 | 00:00:00.006136 | === SPAN START: outbox === | | | outbox | 43
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 348 B | | | |
| | cockroach.streamid: 31 | | | |
2020-07-08 18:33:02.546731+00:00 | 00:00:00.006145 | starting scan with limitBatches true | [n2] | | table reader | 40
2020-07-08 18:33:02.546732+00:00 | 00:00:00.006146 | === SPAN START: outbox === | | | outbox | 44
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 3.0 KiB | | | |
| | cockroach.streamid: 22 | | | |
2020-07-08 18:33:02.546737+00:00 | 00:00:00.006151 | === SPAN START: [async] drain === | | | [async] drain | 45
2020-07-08 18:33:02.546743+00:00 | 00:00:00.006157 | === SPAN START: table reader === | | | table reader | 46
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.processorid: 6 | | | |
| | cockroach.stat.tablereader.bytes.read: 0 B | | | |
| | cockroach.stat.tablereader.input.rows: 0 | | | |
| | cockroach.stat.tablereader.stalltime: 3.423ms | | | |
2020-07-08 18:33:02.546754+00:00 | 00:00:00.006168 | starting scan with limitBatches false | [n1] | | table reader | 46
2020-07-08 18:33:02.546767+00:00 | 00:00:00.006181 | === SPAN START: router output === | | | router output | 47
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 31 | | | |
2020-07-08 18:33:02.546768+00:00 | 00:00:00.006182 | === SPAN START: [async] drain === | | | [async] drain | 48
2020-07-08 18:33:02.546775+00:00 | 00:00:00.006189 | Scan /Table/52/1/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9"{-/#} | [n1] | | table reader | 46
2020-07-08 18:33:02.546776+00:00 | 00:00:00.00619 | === SPAN START: [async] drain === | | | [async] drain | 49
2020-07-08 18:33:02.546779+00:00 | 00:00:00.006193 | === SPAN START: txn coordinator send === | | | txn coordinator send | 50
2020-07-08 18:33:02.546781+00:00 | 00:00:00.006195 | === SPAN START: router output === | | | router output | 52
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 23 | | | |
2020-07-08 18:33:02.546781+00:00 | 00:00:00.006195 | Scan /Table/53/2/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9"{-/PrefixEnd} | [n2] | | table reader | 40
2020-07-08 18:33:02.546781+00:00 | 00:00:00.006195 | === SPAN START: [async] drain === | | | [async] drain | 51
2020-07-08 18:33:02.546785+00:00 | 00:00:00.006199 | === SPAN START: router output === | | | router output | 53
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 10 | | | |
2020-07-08 18:33:02.546786+00:00 | 00:00:00.0062 | === SPAN START: txn coordinator send === | | | txn coordinator send | 54
2020-07-08 18:33:02.546795+00:00 | 00:00:00.006209 | === SPAN START: outbox === | | | outbox | 55
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 17 KiB | | | |
| | cockroach.streamid: 12 | | | |
2020-07-08 18:33:02.546797+00:00 | 00:00:00.006211 | === SPAN START: hash joiner === | | | hash joiner | 56
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.processorid: 14 | | | |
| | cockroach.stat.hashjoiner.disk.max: 0 B | | | |
| | cockroach.stat.hashjoiner.left.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.left.stalltime: 4.204ms | | | |
| | cockroach.stat.hashjoiner.mem.max: 10 KiB | | | |
| | cockroach.stat.hashjoiner.right.input.rows: 1 | | | |
| | cockroach.stat.hashjoiner.right.stalltime: 529µs | | | |
| | cockroach.stat.hashjoiner.stored_side: left | | | |
2020-07-08 18:33:02.5468+00:00 | 00:00:00.006214 | === SPAN START: dist sender send === | | | dist sender send | 57
2020-07-08 18:33:02.546803+00:00 | 00:00:00.006217 | === SPAN START: router output === | | | router output | 58
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 5 | | | |
2020-07-08 18:33:02.546806+00:00 | 00:00:00.00622 | === SPAN START: dist sender send === | | | dist sender send | 59
2020-07-08 18:33:02.546806+00:00 | 00:00:00.00622 | === SPAN START: router output === | | | router output | 60
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 1 | | | |
| | cockroach.streamid: 27 | | | |
2020-07-08 18:33:02.546812+00:00 | 00:00:00.006226 | === SPAN START: router output === | | | router output | 61
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 12 | | | |
| | cockroach.streamid: 1 | | | |
2020-07-08 18:33:02.546814+00:00 | 00:00:00.006228 | === SPAN START: merge joiner === | | | merge joiner | 62
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.processorid: 7 | | | |
| | cockroach.stat.mergejoiner.left.input.rows: 0 | | | |
| | cockroach.stat.mergejoiner.left.stalltime: 1.471ms | | | |
| | cockroach.stat.mergejoiner.mem.max: 0 B | | | |
| | cockroach.stat.mergejoiner.right.input.rows: 0 | | | |
| | cockroach.stat.mergejoiner.right.stalltime: 1.971ms | | | |
2020-07-08 18:33:02.546816+00:00 | 00:00:00.00623 | querying next range at /Table/52/1/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9" | [n1,txn=afc8736a] | | dist sender send | 57
2020-07-08 18:33:02.54682+00:00 | 00:00:00.006234 | querying next range at /Table/53/2/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9" | [n2,txn=afc8736a] | | dist sender send | 59
2020-07-08 18:33:02.546822+00:00 | 00:00:00.006236 | === SPAN START: router output === | | | router output | 63
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 5 | | | |
| | cockroach.streamid: 3 | | | |
2020-07-08 18:33:02.546823+00:00 | 00:00:00.006237 | === SPAN START: router output === | | | router output | 64
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 18 | | | |
2020-07-08 18:33:02.546826+00:00 | 00:00:00.00624 | === SPAN START: hash joiner === | | | hash joiner | 65
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.processorid: 10 | | | |
| | cockroach.stat.hashjoiner.disk.max: 0 B | | | |
| | cockroach.stat.hashjoiner.left.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.left.stalltime: 0s | | | |
| | cockroach.stat.hashjoiner.mem.max: 0 B | | | |
| | cockroach.stat.hashjoiner.right.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.right.stalltime: 4.147ms | | | |
| | cockroach.stat.hashjoiner.stored_side: left | | | |
2020-07-08 18:33:02.54683+00:00 | 00:00:00.006244 | === SPAN START: outbox === | | | outbox | 66
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 349 B | | | |
| | cockroach.streamid: 18 | | | |
2020-07-08 18:33:02.546835+00:00 | 00:00:00.006249 | === SPAN START: outbox === | | | outbox | 67
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 524 B | | | |
| | cockroach.streamid: 8 | | | |
2020-07-08 18:33:02.546839+00:00 | 00:00:00.006253 | === SPAN START: table reader === | | | table reader | 68
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.processorid: 12 | | | |
| | cockroach.stat.tablereader.bytes.read: 162 B | | | |
| | cockroach.stat.tablereader.input.rows: 1 | | | |
| | cockroach.stat.tablereader.stalltime: 328µs | | | |
2020-07-08 18:33:02.546842+00:00 | 00:00:00.006256 | === SPAN START: outbox === | | | outbox | 69
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 3.0 KiB | | | |
| | cockroach.streamid: 33 | | | |
2020-07-08 18:33:02.546847+00:00 | 00:00:00.006261 | === SPAN START: outbox === | | | outbox | 70
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 349 B | | | |
| | cockroach.streamid: 10 | | | |
2020-07-08 18:33:02.546849+00:00 | 00:00:00.006263 | === SPAN START: [async] drain === | | | [async] drain | 71
2020-07-08 18:33:02.546854+00:00 | 00:00:00.006268 | starting scan with limitBatches true | [n1] | | table reader | 68
2020-07-08 18:33:02.546872+00:00 | 00:00:00.006286 | === SPAN START: [async] drain === | | | [async] drain | 72
2020-07-08 18:33:02.546874+00:00 | 00:00:00.006288 | Scan /Table/55/{5-6} | [n1] | | table reader | 68
2020-07-08 18:33:02.546876+00:00 | 00:00:00.00629 | === SPAN START: txn coordinator send === | | | txn coordinator send | 73
2020-07-08 18:33:02.54688+00:00 | 00:00:00.006294 | === SPAN START: [async] drain === | | | [async] drain | 74
2020-07-08 18:33:02.546885+00:00 | 00:00:00.006299 | === SPAN START: [async] drain === | | | [async] drain | 75
2020-07-08 18:33:02.546896+00:00 | 00:00:00.00631 | === SPAN START: dist sender send === | | | dist sender send | 76
2020-07-08 18:33:02.546904+00:00 | 00:00:00.006318 | === SPAN START: [async] drain === | | | [async] drain | 77
2020-07-08 18:33:02.546905+00:00 | 00:00:00.006319 | querying next range at /Table/55/5 | [n1,txn=afc8736a] | | dist sender send | 76
2020-07-08 18:33:02.546905+00:00 | 00:00:00.006319 | === SPAN START: outbox === | | | outbox | 78
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 3.0 KiB | | | |
| | cockroach.streamid: 21 | | | |
2020-07-08 18:33:02.546908+00:00 | 00:00:00.006322 | r34: sending batch 1 Scan to (n2,s2):3 | [n2,txn=afc8736a] | | dist sender send | 59
2020-07-08 18:33:02.546909+00:00 | 00:00:00.006323 | === SPAN START: router output === | | | router output | 79
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 1 | | | |
| | cockroach.streamid: 8 | | | |
2020-07-08 18:33:02.546913+00:00 | 00:00:00.006327 | sending request to local client | [n2,txn=afc8736a] | | dist sender send | 59
2020-07-08 18:33:02.546914+00:00 | 00:00:00.006328 | r33: sending batch 1 Scan to (n1,s1):1 | [n1,txn=afc8736a] | | dist sender send | 57
2020-07-08 18:33:02.546918+00:00 | 00:00:00.006332 | sending request to local client | [n1,txn=afc8736a] | | dist sender send | 57
2020-07-08 18:33:02.546918+00:00 | 00:00:00.006332 | === SPAN START: table reader === | | | table reader | 80
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.processorid: 1 | | | |
| | cockroach.stat.tablereader.bytes.read: 1.1 KiB | | | |
| | cockroach.stat.tablereader.input.rows: 17 | | | |
| | cockroach.stat.tablereader.stalltime: 326µs | | | |
2020-07-08 18:33:02.546918+00:00 | 00:00:00.006332 | === SPAN START: /cockroach.roachpb.Internal/Batch === | | | /cockroach.roachpb.Internal/Batch | 81
2020-07-08 18:33:02.546924+00:00 | 00:00:00.006338 | === SPAN START: /cockroach.roachpb.Internal/Batch === | | | /cockroach.roachpb.Internal/Batch | 82
2020-07-08 18:33:02.546924+00:00 | 00:00:00.006338 | node received request: 1 Scan | [n2] | | /cockroach.roachpb.Internal/Batch | 81
2020-07-08 18:33:02.546927+00:00 | 00:00:00.006341 | === SPAN START: flow === | | | flow | 83
2020-07-08 18:33:02.54693+00:00 | 00:00:00.006344 | node received request: 1 Scan | [n1] | | /cockroach.roachpb.Internal/Batch | 82
2020-07-08 18:33:02.546943+00:00 | 00:00:00.006357 | === SPAN START: router output === | | | router output | 84
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 12 | | | |
2020-07-08 18:33:02.546947+00:00 | 00:00:00.006361 | === SPAN START: router output === | | | router output | 85
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 15 | | | |
2020-07-08 18:33:02.546948+00:00 | 00:00:00.006362 | === SPAN START: [async] drain === | | | [async] drain | 86
2020-07-08 18:33:02.546948+00:00 | 00:00:00.006362 | starting scan with limitBatches true | [n1] | | table reader | 80
2020-07-08 18:33:02.546963+00:00 | 00:00:00.006377 | Scan /Table/56/{2-3} | [n1] | | table reader | 80
2020-07-08 18:33:02.546963+00:00 | 00:00:00.006377 | executing [txn: afc8736a], Scan [/Table/52/1/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9",/Table/52/1/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9"/#) | [n1,s1] | | /cockroach.roachpb.Internal/Batch | 82
2020-07-08 18:33:02.546966+00:00 | 00:00:00.00638 | === SPAN START: txn coordinator send === | | | txn coordinator send | 87
2020-07-08 18:33:02.546976+00:00 | 00:00:00.00639 | read-only path | [n1,s1,r33/1:/Table/5{2-3}] | | /cockroach.roachpb.Internal/Batch | 82
2020-07-08 18:33:02.546989+00:00 | 00:00:00.006403 | r36: sending batch 1 Scan to (n1,s1):1 | [n1,txn=afc8736a] | | dist sender send | 76
2020-07-08 18:33:02.546993+00:00 | 00:00:00.006407 | === SPAN START: dist sender send === | | | dist sender send | 88
2020-07-08 18:33:02.546993+00:00 | 00:00:00.006407 | sending request to local client | [n1,txn=afc8736a] | | dist sender send | 76
2020-07-08 18:33:02.546994+00:00 | 00:00:00.006408 | sequencing request | [n1,s1,r33/1:/Table/5{2-3}] | | /cockroach.roachpb.Internal/Batch | 82
2020-07-08 18:33:02.546995+00:00 | 00:00:00.006409 | executing [txn: afc8736a], Scan [/Table/53/2/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9",/Table/53/2/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9"/PrefixEnd) | [n2,s2] | | /cockroach.roachpb.Internal/Batch | 81
2020-07-08 18:33:02.546997+00:00 | 00:00:00.006411 | acquiring latches | [n1,s1,r33/1:/Table/5{2-3}] | | /cockroach.roachpb.Internal/Batch | 82
2020-07-08 18:33:02.547+00:00 | 00:00:00.006414 | === SPAN START: /cockroach.roachpb.Internal/Batch === | | | /cockroach.roachpb.Internal/Batch | 89
2020-07-08 18:33:02.547005+00:00 | 00:00:00.006419 | node received request: 1 Scan | [n1] | | /cockroach.roachpb.Internal/Batch | 89
2020-07-08 18:33:02.547005+00:00 | 00:00:00.006419 | scanning lock table for conflicting locks | [n1,s1,r33/1:/Table/5{2-3}] | | /cockroach.roachpb.Internal/Batch | 82
2020-07-08 18:33:02.547005+00:00 | 00:00:00.006419 | querying next range at /Table/56/2 | [n1,txn=afc8736a] | | dist sender send | 88
2020-07-08 18:33:02.547006+00:00 | 00:00:00.00642 | read-only path | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 81
2020-07-08 18:33:02.547013+00:00 | 00:00:00.006427 | waiting in lock wait-queues | [n1,s1,r33/1:/Table/5{2-3}] | | /cockroach.roachpb.Internal/Batch | 82
2020-07-08 18:33:02.547025+00:00 | 00:00:00.006439 | sequencing request | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 81
2020-07-08 18:33:02.547026+00:00 | 00:00:00.00644 | executing [txn: afc8736a], Scan [/Table/55/5,/Table/55/6) | [n1,s1] | | /cockroach.roachpb.Internal/Batch | 89
2020-07-08 18:33:02.547027+00:00 | 00:00:00.006441 | acquiring latches | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 81
2020-07-08 18:33:02.547035+00:00 | 00:00:00.006449 | read-only path | [n1,s1,r36/1:/Table/5{5-6}] | | /cockroach.roachpb.Internal/Batch | 89
2020-07-08 18:33:02.547037+00:00 | 00:00:00.006451 | scanning lock table for conflicting locks | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 81
2020-07-08 18:33:02.547042+00:00 | 00:00:00.006456 | waiting for read lock | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 81
2020-07-08 18:33:02.54705+00:00 | 00:00:00.006464 | sequencing request | [n1,s1,r36/1:/Table/5{5-6}] | | /cockroach.roachpb.Internal/Batch | 89
2020-07-08 18:33:02.547054+00:00 | 00:00:00.006468 | acquiring latches | [n1,s1,r36/1:/Table/5{5-6}] | | /cockroach.roachpb.Internal/Batch | 89
2020-07-08 18:33:02.547062+00:00 | 00:00:00.006476 | scanning lock table for conflicting locks | [n1,s1,r36/1:/Table/5{5-6}] | | /cockroach.roachpb.Internal/Batch | 89
2020-07-08 18:33:02.547067+00:00 | 00:00:00.006481 | waiting for read lock | [n1,s1,r36/1:/Table/5{5-6}] | | /cockroach.roachpb.Internal/Batch | 89
2020-07-08 18:33:02.54707+00:00 | 00:00:00.006484 | r37: sending batch 1 Scan to (n1,s1):1 | [n1,txn=afc8736a] | | dist sender send | 88
2020-07-08 18:33:02.547075+00:00 | 00:00:00.006489 | sending request to local client | [n1,txn=afc8736a] | | dist sender send | 88
2020-07-08 18:33:02.547079+00:00 | 00:00:00.006493 | === SPAN START: /cockroach.roachpb.Internal/Batch === | | | /cockroach.roachpb.Internal/Batch | 90
2020-07-08 18:33:02.547084+00:00 | 00:00:00.006498 | node received request: 1 Scan | [n1] | | /cockroach.roachpb.Internal/Batch | 90
2020-07-08 18:33:02.547103+00:00 | 00:00:00.006517 | executing [txn: afc8736a], Scan [/Table/56/2,/Table/56/3) | [n1,s1] | | /cockroach.roachpb.Internal/Batch | 90
2020-07-08 18:33:02.547107+00:00 | 00:00:00.006521 | Consumer sent handshake. Consuming flow scheduled: true | [n2] | | [async] drain | 13
2020-07-08 18:33:02.547112+00:00 | 00:00:00.006526 | read-only path | [n1,s1,r37/1:/Table/5{6-7}] | | /cockroach.roachpb.Internal/Batch | 90
2020-07-08 18:33:02.547128+00:00 | 00:00:00.006542 | sequencing request | [n1,s1,r37/1:/Table/5{6-7}] | | /cockroach.roachpb.Internal/Batch | 90
2020-07-08 18:33:02.547131+00:00 | 00:00:00.006545 | acquiring latches | [n1,s1,r37/1:/Table/5{6-7}] | | /cockroach.roachpb.Internal/Batch | 90
2020-07-08 18:33:02.547138+00:00 | 00:00:00.006552 | Consumer sent handshake. Consuming flow scheduled: true | [n2] | | [async] drain | 45
2020-07-08 18:33:02.547139+00:00 | 00:00:00.006553 | scanning lock table for conflicting locks | [n1,s1,r37/1:/Table/5{6-7}] | | /cockroach.roachpb.Internal/Batch | 90
2020-07-08 18:33:02.547141+00:00 | 00:00:00.006555 | read completed | [n1,s1,r36/1:/Table/5{5-6}] | | /cockroach.roachpb.Internal/Batch | 89
2020-07-08 18:33:02.547143+00:00 | 00:00:00.006557 | waiting for read lock | [n1,s1,r37/1:/Table/5{6-7}] | | /cockroach.roachpb.Internal/Batch | 90
2020-07-08 18:33:02.547148+00:00 | 00:00:00.006562 | read completed | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 81
2020-07-08 18:33:02.547155+00:00 | 00:00:00.006569 | starting (3 processors, 6 startables) | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | flow | 83
2020-07-08 18:33:02.54717+00:00 | 00:00:00.006584 | recording span to refresh: /Table/55/{5-6} | [n1,txn=afc8736a] | | txn coordinator send | 73
2020-07-08 18:33:02.547174+00:00 | 00:00:00.006588 | Consumer sent handshake. Consuming flow scheduled: false | [n2] | | [async] drain | 49
2020-07-08 18:33:02.547182+00:00 | 00:00:00.006596 | Consumer sent handshake. Consuming flow scheduled: false | [n2] | | [async] drain | 22
2020-07-08 18:33:02.54721+00:00 | 00:00:00.006624 | Consumer sent handshake. Consuming flow scheduled: true | [n2] | | [async] drain | 26
2020-07-08 18:33:02.547213+00:00 | 00:00:00.006627 | recording span to refresh: /Table/53/2/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9"{-/PrefixEnd} | [n2,txn=afc8736a] | | txn coordinator send | 54
2020-07-08 18:33:02.547222+00:00 | 00:00:00.006636 | === SPAN START: index joiner === | | | index joiner | 91
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.processorid: 3 | | | |
| | cockroach.stat.joinreader.index.input.rows: 2 | | | |
| | cockroach.stat.joinreader.index.stalltime: 252µs | | | |
| | cockroach.stat.joinreader.input.rows: 2 | | | |
| | cockroach.stat.joinreader.stalltime: 49µs | | | |
2020-07-08 18:33:02.547227+00:00 | 00:00:00.006641 | Consumer sent handshake. Consuming flow scheduled: true | [n2] | | [async] drain | 15
2020-07-08 18:33:02.54723+00:00 | 00:00:00.006644 | read completed | [n1,s1,r37/1:/Table/5{6-7}] | | /cockroach.roachpb.Internal/Batch | 90
2020-07-08 18:33:02.547257+00:00 | 00:00:00.006671 | recording span to refresh: /Table/56/{2-3} | [n1,txn=afc8736a] | | txn coordinator send | 87
2020-07-08 18:33:02.547306+00:00 | 00:00:00.00672 | Scan /Table/53/1/"v?\x04*EkF\xe4\xa1*\x81E\x1de\"Q"{-/#}, /Table/53/1/"Ծ\x8a\xaeh{E\xe8\x83\xc98C\\\xa9eZ"{-/#} | [n2] | | index joiner | 91
2020-07-08 18:33:02.547308+00:00 | 00:00:00.006722 | === SPAN START: txn coordinator send === | | | txn coordinator send | 92
2020-07-08 18:33:02.547315+00:00 | 00:00:00.006729 | === SPAN START: dist sender send === | | | dist sender send | 93
2020-07-08 18:33:02.547318+00:00 | 00:00:00.006732 | Consumer sent handshake. Consuming flow scheduled: false | [n1] | | [async] drain | 75
2020-07-08 18:33:02.547327+00:00 | 00:00:00.006741 | querying next range at /Table/53/1/"v?\x04*EkF\xe4\xa1*\x81E\x1de\"Q" | [n2,txn=afc8736a] | | dist sender send | 93
2020-07-08 18:33:02.547348+00:00 | 00:00:00.006762 | Consumer sent handshake. Consuming flow scheduled: false | [n2] | | [async] drain | 30
2020-07-08 18:33:02.547351+00:00 | 00:00:00.006765 | r34: sending batch 2 Scan to (n2,s2):3 | [n2,txn=afc8736a] | | dist sender send | 93
2020-07-08 18:33:02.547353+00:00 | 00:00:00.006767 | sending request to local client | [n2,txn=afc8736a] | | dist sender send | 93
2020-07-08 18:33:02.547355+00:00 | 00:00:00.006769 | === SPAN START: /cockroach.roachpb.Internal/Batch === | | | /cockroach.roachpb.Internal/Batch | 94
2020-07-08 18:33:02.547356+00:00 | 00:00:00.00677 | Consumer sent handshake. Consuming flow scheduled: true | [n1] | | [async] drain | 72
2020-07-08 18:33:02.547358+00:00 | 00:00:00.006772 | node received request: 2 Scan | [n2] | | /cockroach.roachpb.Internal/Batch | 94
2020-07-08 18:33:02.547368+00:00 | 00:00:00.006782 | Consumer sent handshake. Consuming flow scheduled: true | [n1] | | [async] drain | 48
2020-07-08 18:33:02.547372+00:00 | 00:00:00.006786 | Consumer sent handshake. Consuming flow scheduled: true | [n1] | | [async] drain | 74
2020-07-08 18:33:02.547376+00:00 | 00:00:00.00679 | executing [txn: afc8736a], Scan [/Table/53/1/"v?\x04*EkF\xe4\xa1*\x81E\x1de\"Q",/Table/53/1/"v?\x04*EkF\xe4\xa1*\x81E\x1de\"Q"/#), Scan [/Table/53/1/"Ծ\x8a\xaeh{E\xe8\x83\xc98C\\\xa9eZ",/Table/53/1/"Ծ\x8a\xaeh{E\xe8\x83\xc98C\\\xa9eZ"/#) | [n2,s2] | | /cockroach.roachpb.Internal/Batch | 94
2020-07-08 18:33:02.547382+00:00 | 00:00:00.006796 | read-only path | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 94
2020-07-08 18:33:02.547385+00:00 | 00:00:00.006799 | Consumer sent handshake. Consuming flow scheduled: true | [n1] | | [async] drain | 38
2020-07-08 18:33:02.547385+00:00 | 00:00:00.006799 | Consumer sent handshake. Consuming flow scheduled: true | [n1] | | [async] drain | 77
2020-07-08 18:33:02.547387+00:00 | 00:00:00.006801 | === SPAN START: noop === | | | noop | 95
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.processorid: 16 | | | |
2020-07-08 18:33:02.547393+00:00 | 00:00:00.006807 | sequencing request | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 94
2020-07-08 18:33:02.547395+00:00 | 00:00:00.006809 | acquiring latches | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 94
2020-07-08 18:33:02.547404+00:00 | 00:00:00.006818 | === SPAN START: hash joiner === | | | hash joiner | 96
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.processorid: 13 | | | |
| | cockroach.stat.hashjoiner.disk.max: 0 B | | | |
| | cockroach.stat.hashjoiner.left.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.left.stalltime: 0s | | | |
| | cockroach.stat.hashjoiner.mem.max: 0 B | | | |
| | cockroach.stat.hashjoiner.right.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.right.stalltime: 396µs | | | |
| | cockroach.stat.hashjoiner.stored_side: left | | | |
2020-07-08 18:33:02.547404+00:00 | 00:00:00.006818 | scanning lock table for conflicting locks | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 94
2020-07-08 18:33:02.547407+00:00 | 00:00:00.006821 | waiting for read lock | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 94
2020-07-08 18:33:02.547416+00:00 | 00:00:00.00683 | Consumer sent handshake. Consuming flow scheduled: false | [n1] | | [async] drain | 36
2020-07-08 18:33:02.547424+00:00 | 00:00:00.006838 | === SPAN START: router output === | | | router output | 97
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 14 | | | |
2020-07-08 18:33:02.547431+00:00 | 00:00:00.006845 | === SPAN START: router output === | | | router output | 98
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 1 | | | |
| | cockroach.streamid: 11 | | | |
2020-07-08 18:33:02.547433+00:00 | 00:00:00.006847 | === SPAN START: router output === | | | router output | 99
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 4 | | | |
| | cockroach.streamid: 17 | | | |
2020-07-08 18:33:02.547439+00:00 | 00:00:00.006853 | === SPAN START: outbox === | | | outbox | 100
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 406 B | | | |
| | cockroach.streamid: 24 | | | |
2020-07-08 18:33:02.54749+00:00 | 00:00:00.006904 | read completed | [n2,s2,r34/3:/Table/5{3-4}] | | /cockroach.roachpb.Internal/Batch | 94
2020-07-08 18:33:02.547491+00:00 | 00:00:00.006905 | === SPAN START: [async] drain === | | | [async] drain | 101
2020-07-08 18:33:02.547506+00:00 | 00:00:00.00692 | === SPAN START: router output === | | | router output | 102
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 28 | | | |
2020-07-08 18:33:02.547518+00:00 | 00:00:00.006932 | === SPAN START: router output === | | | router output | 103
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 20 | | | |
2020-07-08 18:33:02.547518+00:00 | 00:00:00.006932 | recording span to refresh: /Table/53/1/"v?\x04*EkF\xe4\xa1*\x81E\x1de\"Q"{-/#} | [n2,txn=afc8736a] | | txn coordinator send | 92
2020-07-08 18:33:02.547521+00:00 | 00:00:00.006935 | === SPAN START: router output === | | | router output | 104
| | cockroach.stat.routeroutput.disk.max: 0 | | | |
| | cockroach.stat.routeroutput.mem.max: 0 | | | |
| | cockroach.stat.routeroutput.rows_routed: 0 | | | |
| | cockroach.streamid: 24 | | | |
2020-07-08 18:33:02.547529+00:00 | 00:00:00.006943 | === SPAN START: outbox === | | | outbox | 105
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 405 B | | | |
| | cockroach.streamid: 14 | | | |
2020-07-08 18:33:02.54753+00:00 | 00:00:00.006944 | recording span to refresh: /Table/53/1/"Ծ\x8a\xaeh{E\xe8\x83\xc98C\\\xa9eZ"{-/#} | [n2,txn=afc8736a] | | txn coordinator send | 92
2020-07-08 18:33:02.547539+00:00 | 00:00:00.006953 | === SPAN START: hash joiner === | | | hash joiner | 106
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.processorid: 9 | | | |
| | cockroach.stat.hashjoiner.disk.max: 0 B | | | |
| | cockroach.stat.hashjoiner.left.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.left.stalltime: 0s | | | |
| | cockroach.stat.hashjoiner.mem.max: 0 B | | | |
| | cockroach.stat.hashjoiner.right.input.rows: 0 | | | |
| | cockroach.stat.hashjoiner.right.stalltime: 3.046ms | | | |
| | cockroach.stat.hashjoiner.stored_side: left | | | |
2020-07-08 18:33:02.547544+00:00 | 00:00:00.006958 | === SPAN START: outbox === | | | outbox | 107
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 406 B | | | |
| | cockroach.streamid: 28 | | | |
2020-07-08 18:33:02.547547+00:00 | 00:00:00.006961 | === SPAN START: outbox === | | | outbox | 108
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.stat.outbox.bytes_sent: 616 B | | | |
| | cockroach.streamid: 17 | | | |
2020-07-08 18:33:02.547556+00:00 | 00:00:00.00697 | === SPAN START: table reader === | | | table reader | 109
| | cockroach.flowid: b72bb6ec-610b-48b5-bb1f-bea9683ef4ac | | | |
| | cockroach.processorid: 0 | | | |
| | cockroach.stat.tablereader.bytes.read: 588 B | | | |
| | cockroach.stat.tablereader.input.rows: 5 | | | |
| | cockroach.stat.tablereader.stalltime: 377µs | | | |
2020-07-08 18:33:02.547565+00:00 | 00:00:00.006979 | starting scan with limitBatches true | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | table reader | 109
2020-07-08 18:33:02.547568+00:00 | 00:00:00.006982 | Consumer sent handshake. Consuming flow scheduled: false | [n1] | | [async] drain | 71
2020-07-08 18:33:02.547573+00:00 | 00:00:00.006987 | Consumer sent handshake. Consuming flow scheduled: true | [n1] | | [async] drain | 71
2020-07-08 18:33:02.547574+00:00 | 00:00:00.006988 | Consumer sent handshake. Consuming flow scheduled: false | [n1] | | [async] drain | 86
2020-07-08 18:33:02.547582+00:00 | 00:00:00.006996 | Consumer sent handshake. Consuming flow scheduled: true | [n1] | | [async] drain | 86
2020-07-08 18:33:02.547587+00:00 | 00:00:00.007001 | Scan /Table/58/{1-2} | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | table reader | 109
2020-07-08 18:33:02.547588+00:00 | 00:00:00.007002 | === SPAN START: [async] drain === | | | [async] drain | 110
2020-07-08 18:33:02.54759+00:00 | 00:00:00.007004 | === SPAN START: txn coordinator send === | | | txn coordinator send | 111
2020-07-08 18:33:02.547599+00:00 | 00:00:00.007013 | === SPAN START: [async] drain === | | | [async] drain | 112
2020-07-08 18:33:02.547601+00:00 | 00:00:00.007015 | Consumer sent handshake. Consuming flow scheduled: true | [n1] | | [async] drain | 75
2020-07-08 18:33:02.547602+00:00 | 00:00:00.007016 | === SPAN START: [async] drain === | | | [async] drain | 113
2020-07-08 18:33:02.547622+00:00 | 00:00:00.007036 | === SPAN START: dist sender send === | | | dist sender send | 114
2020-07-08 18:33:02.547628+00:00 | 00:00:00.007042 | Consumer sent handshake. Consuming flow scheduled: true | [n2] | | [async] drain | 22
2020-07-08 18:33:02.547634+00:00 | 00:00:00.007048 | querying next range at /Table/58/1 | [n3,client=172.18.0.4:40358,hostnossl,user=root,txn=afc8736a] | | dist sender send | 114
2020-07-08 18:33:02.547636+00:00 | 00:00:00.00705 | Consumer sent handshake. Consuming flow scheduled: true | [n2] | | [async] drain | 30
2020-07-08 18:33:02.547647+00:00 | 00:00:00.007061 | Consumer sent handshake. Consuming flow scheduled: true | [n2] | | [async] drain | 49
2020-07-08 18:33:02.547712+00:00 | 00:00:00.007126 | r39: sending batch 1 Scan to (n3,s3):2 | [n3,client=172.18.0.4:40358,hostnossl,user=root,txn=afc8736a] | | dist sender send | 114
2020-07-08 18:33:02.547716+00:00 | 00:00:00.00713 | sending request to local client | [n3,client=172.18.0.4:40358,hostnossl,user=root,txn=afc8736a] | | dist sender send | 114
2020-07-08 18:33:02.54772+00:00 | 00:00:00.007134 | === SPAN START: /cockroach.roachpb.Internal/Batch === | | | /cockroach.roachpb.Internal/Batch | 115
2020-07-08 18:33:02.547724+00:00 | 00:00:00.007138 | node received request: 1 Scan | [n3] | | /cockroach.roachpb.Internal/Batch | 115
2020-07-08 18:33:02.547746+00:00 | 00:00:00.00716 | executing [txn: afc8736a], Scan [/Table/58/1,/Table/58/2) | [n3,s3] | | /cockroach.roachpb.Internal/Batch | 115
2020-07-08 18:33:02.547756+00:00 | 00:00:00.00717 | read-only path | [n3,s3,r39/2:/{Table/58-Max}] | | /cockroach.roachpb.Internal/Batch | 115
2020-07-08 18:33:02.547763+00:00 | 00:00:00.007177 | read has no clock uncertainty | [n3,s3,r39/2:/{Table/58-Max}] | | /cockroach.roachpb.Internal/Batch | 115
2020-07-08 18:33:02.547775+00:00 | 00:00:00.007189 | sequencing request | [n3,s3,r39/2:/{Table/58-Max}] | | /cockroach.roachpb.Internal/Batch | 115
2020-07-08 18:33:02.547778+00:00 | 00:00:00.007192 | acquiring latches | [n3,s3,r39/2:/{Table/58-Max}] | | /cockroach.roachpb.Internal/Batch | 115
2020-07-08 18:33:02.547789+00:00 | 00:00:00.007203 | scanning lock table for conflicting locks | [n3,s3,r39/2:/{Table/58-Max}] | | /cockroach.roachpb.Internal/Batch | 115
2020-07-08 18:33:02.547793+00:00 | 00:00:00.007207 | waiting for read lock | [n3,s3,r39/2:/{Table/58-Max}] | | /cockroach.roachpb.Internal/Batch | 115
2020-07-08 18:33:02.547824+00:00 | 00:00:00.007238 | Consumer sent handshake. Consuming flow scheduled: true | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | [async] drain | 110
2020-07-08 18:33:02.547831+00:00 | 00:00:00.007245 | Consumer sent handshake. Consuming flow scheduled: true | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | [async] drain | 101
2020-07-08 18:33:02.547888+00:00 | 00:00:00.007302 | read completed | [n3,s3,r39/2:/{Table/58-Max}] | | /cockroach.roachpb.Internal/Batch | 115
2020-07-08 18:33:02.547892+00:00 | 00:00:00.007306 | Consumer sent handshake. Consuming flow scheduled: true | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | [async] drain | 113
2020-07-08 18:33:02.547899+00:00 | 00:00:00.007313 | Consumer sent handshake. Consuming flow scheduled: true | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | [async] drain | 112
2020-07-08 18:33:02.547931+00:00 | 00:00:00.007345 | recording span to refresh: /Table/58/{1-2} | [n3,client=172.18.0.4:40358,hostnossl,user=root,txn=afc8736a] | | txn coordinator send | 111
2020-07-08 18:33:02.550011+00:00 | 00:00:00.009425 | acquiring latches | [n1,s1,r33/1:/Table/5{2-3}] | | /cockroach.roachpb.Internal/Batch | 82
2020-07-08 18:33:02.550016+00:00 | 00:00:00.00943 | scanning lock table for conflicting locks | [n1,s1,r33/1:/Table/5{2-3}] | | /cockroach.roachpb.Internal/Batch | 82
2020-07-08 18:33:02.55002+00:00 | 00:00:00.009434 | waiting for read lock | [n1,s1,r33/1:/Table/5{2-3}] | | /cockroach.roachpb.Internal/Batch | 82
2020-07-08 18:33:02.55012+00:00 | 00:00:00.009534 | ReadWithinUncertaintyIntervalError: read at time 1594233182.540697747,0 encountered previous write with future timestamp 1594233182.545730205,0 within uncertainty interval `t <= 1594233182.546935404,0`; observed timestamps: [{1 1594233182.546935404,0} {3 1594233182.540697747,0}] | [n1,s1,r33/1:/Table/5{2-3}] | | /cockroach.roachpb.Internal/Batch | 82
2020-07-08 18:33:02.550129+00:00 | 00:00:00.009543 | replica.Send got error: ReadWithinUncertaintyIntervalError: read at time 1594233182.540697747,0 encountered previous write with future timestamp 1594233182.545730205,0 within uncertainty interval `t <= 1594233182.546935404,0`; observed timestamps: [{1 1594233182.546935404,0} {3 1594233182.540697747,0}] | [n1,s1,r33/1:/Table/5{2-3}] | | /cockroach.roachpb.Internal/Batch | 82
2020-07-08 18:33:02.550133+00:00 | 00:00:00.009547 | *roachpb.ReadWithinUncertaintyIntervalError | [n1] | | /cockroach.roachpb.Internal/Batch | 82
2020-07-08 18:33:02.55017+00:00 | 00:00:00.009584 | reply error [txn: afc8736a], Scan [/Table/52/1/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9",/Table/52/1/"\xa6NڍQ\x14Ou\x9a\u008b\x8f\xf0\x00+\xd9"/#): ReadWithinUncertaintyIntervalError: read at time 1594233182.540697747,0 encountered previous write with future timestamp 1594233182.545730205,0 within uncertainty interval `t <= 1594233182.546935404,0`; observed timestamps: [{1 1594233182.546935404,0} {3 1594233182.540697747,0}] | [n1,txn=afc8736a] | | dist sender send | 57
2020-07-08 18:33:02.551965+00:00 | 00:00:00.011379 | execution ends | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.551968+00:00 | 00:00:00.011382 | rows affected: 0 | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.551995+00:00 | 00:00:00.011409 | AutoCommit. err: <nil> | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 3
2020-07-08 18:33:02.552006+00:00 | 00:00:00.011419 | releasing 5 tables | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | session recording | 0
2020-07-08 18:33:02.552017+00:00 | 00:00:00.011431 | === SPAN START: exec stmt === | | | exec stmt | 116
2020-07-08 18:33:02.55203+00:00 | 00:00:00.011444 | [NoTxn pos:2] executing ExecStmt: SET TRACING = off | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 116
2020-07-08 18:33:02.552036+00:00 | 00:00:00.01145 | executing: SET TRACING = off in state: NoTxn | [n3,client=172.18.0.4:40358,hostnossl,user=root] | | exec stmt | 116
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment