github.com/cockroachdb/cockroach@v20.2.0-alpha.1+incompatible/pkg/sql/opt/exec/execbuilder/testdata/show_trace (about)

     1  # LogicTest: local
     2  
     3  skip https://github.com/cockroachdb/cockroach/issues/43043
     4  
     5  # Check SHOW KV TRACE FOR SESSION.
     6  
     7  statement ok
     8  SET tracing = on,kv,results; CREATE DATABASE t; SET tracing = off
     9  
    10  # Check the KV trace; we need to remove the eventlog entry and
    11  # internal queries since the timestamp is non-deterministic.
    12  query TT
    13  SELECT operation, message FROM [SHOW KV TRACE FOR SESSION]
    14  WHERE message NOT LIKE '%Z/%'
    15    AND operation NOT LIKE 'kv.DistSender: sending partial batch%'  -- order of partial batches is not deterministic
    16    AND message NOT SIMILAR TO '%(PushTxn|ResolveIntent|SystemConfigSpan)%'
    17    AND tag NOT LIKE '%intExec=%'
    18    AND tag NOT LIKE '%scExec%'
    19    AND tag NOT LIKE '%IndexBackfiller%'
    20    AND operation != 'dist sender send'
    21  ----
    22  flow       CPut /NamespaceTable/30/1/0/0/"t"/4/1 -> 53
    23  flow       CPut /Table/3/1/53/2/1 -> database:<name:"t" id:53 privileges:<users:<user:"admin" privileges:2 > users:<user:"root" privileges:2 > > >
    24  flow       CPut /NamespaceTable/30/1/53/0/"public"/4/1 -> 29
    25  exec stmt  rows affected: 0
    26  
    27  
    28  # More KV operations.
    29  statement ok
    30  SET tracing = on,kv,results; CREATE TABLE t.kv(k INT PRIMARY KEY, v INT, FAMILY "primary" (k, v)); SET tracing = off
    31  
    32  query TT
    33  SELECT operation, regexp_replace(regexp_replace(message, 'wall_time:\d+', 'wall_time:...'), 'wall_time:\d+', 'wall_time:...') as message
    34    FROM [SHOW KV TRACE FOR SESSION]
    35  WHERE message NOT LIKE '%Z/%'
    36    AND operation NOT LIKE 'kv.DistSender: sending partial batch%'  -- order of partial batches is not deterministic
    37    AND message NOT SIMILAR TO '%(PushTxn|ResolveIntent|SystemConfigSpan)%'
    38    AND tag NOT LIKE '%intExec=%'
    39    AND tag NOT LIKE '%scExec%'
    40    AND tag NOT LIKE '%IndexBackfiller%'
    41    AND operation != 'dist sender send'
    42  ----
    43  flow       CPut /NamespaceTable/30/1/53/29/"kv"/4/1 -> 54
    44  flow       CPut /Table/3/1/54/2/1 -> table:<name:"kv" id:54 parent_id:53 unexposed_parent_schema_id:29 version:1 modification_time:<> columns:<name:"k" id:1 type:<InternalType:<family:IntFamily width:64 precision:0 locale:"" visible_type:0 oid:20 time_precision_is_set:false > > nullable:false hidden:false > columns:<name:"v" id:2 type:<InternalType:<family:IntFamily width:64 precision:0 locale:"" visible_type:0 oid:20 time_precision_is_set:false > > nullable:true hidden:false > next_column_id:3 families:<name:"primary" id:0 column_names:"k" column_names:"v" column_ids:1 column_ids:2 default_column_id:2 > next_family_id:1 primary_index:<name:"primary" id:1 unique:true version:1 column_names:"k" column_directions:ASC column_ids:1 foreign_key:<table:0 index:0 name:"" validity:Validated shared_prefix_len:0 on_delete:NO_ACTION on_update:NO_ACTION match:SIMPLE > interleave:<> partitioning:<num_columns:0 > type:FORWARD created_explicitly:false encoding_type:0 sharded:<is_sharded:false name:"" shard_buckets:0 > > next_index_id:2 privileges:<users:<user:"admin" privileges:2 > users:<user:"root" privileges:2 > > next_mutation_id:1 format_version:3 state:PUBLIC offline_reason:"" view_query:"" drop_time:0 replacement_of:<id:0 time:<> > audit_mode:DISABLED drop_job_id:0 create_query:"" create_as_of_time:<> temporary:false >
    45  exec stmt  rows affected: 0
    46  
    47  # We avoid using the full trace output, because that would make the
    48  # ensuing trace especially chatty, as it traces the index backfill at
    49  # the end of the implicit transaction. A chatty trace could be OK in
    50  # tests, however the backfill also incur job table traffic which has a
    51  # timestamp index, and we can't use (non-deterministic) timestamp
    52  # values in expected values.
    53  statement ok
    54  SET tracing = on,kv,results; CREATE UNIQUE INDEX woo ON t.kv(v); SET tracing = off
    55  
    56  query TT
    57  SELECT operation,
    58         regexp_replace(regexp_replace(regexp_replace(message, 'wall_time:\d+', 'wall_time:...'), 'mutationJobs:<[^>]*>', 'mutationJobs:<...>'), 'wall_time:\d+', 'wall_time:...') as message
    59    FROM [SHOW KV TRACE FOR SESSION]
    60  WHERE message NOT LIKE '%Z/%' AND message NOT LIKE 'querying next range at%'
    61    AND operation NOT LIKE 'kv.DistSender: sending partial batch%'  -- order of partial batches is not deterministic
    62    /* since the transactions involved are multi-range, intent resolving is async and
    63    sometimes there's still intents around */
    64    AND message NOT SIMILAR TO '%(PushTxn|ResolveIntent|SystemConfigSpan)%'
    65    AND tag NOT LIKE '%intExec=%'
    66    AND tag NOT LIKE '%scExec%'
    67    AND tag NOT LIKE '%IndexBackfiller%'
    68    AND operation != 'dist sender send'
    69  ----
    70  flow       Put /Table/3/1/54/2/1 -> table:<name:"kv" id:54 parent_id:53 unexposed_parent_schema_id:29 version:2 modification_time:<> columns:<name:"k" id:1 type:<InternalType:<family:IntFamily width:64 precision:0 locale:"" visible_type:0 oid:20 time_precision_is_set:false > > nullable:false hidden:false > columns:<name:"v" id:2 type:<InternalType:<family:IntFamily width:64 precision:0 locale:"" visible_type:0 oid:20 time_precision_is_set:false > > nullable:true hidden:false > next_column_id:3 families:<name:"primary" id:0 column_names:"k" column_names:"v" column_ids:1 column_ids:2 default_column_id:2 > next_family_id:1 primary_index:<name:"primary" id:1 unique:true version:1 column_names:"k" column_directions:ASC column_ids:1 foreign_key:<table:0 index:0 name:"" validity:Validated shared_prefix_len:0 on_delete:NO_ACTION on_update:NO_ACTION match:SIMPLE > interleave:<> partitioning:<num_columns:0 > type:FORWARD created_explicitly:false encoding_type:0 sharded:<is_sharded:false name:"" shard_buckets:0 > > next_index_id:3 privileges:<users:<user:"admin" privileges:2 > users:<user:"root" privileges:2 > > mutations:<index:<name:"woo" id:2 unique:true version:1 column_names:"v" column_directions:ASC column_ids:2 extra_column_ids:1 foreign_key:<table:0 index:0 name:"" validity:Validated shared_prefix_len:0 on_delete:NO_ACTION on_update:NO_ACTION match:SIMPLE > interleave:<> partitioning:<num_columns:0 > type:FORWARD created_explicitly:true encoding_type:0 sharded:<is_sharded:false name:"" shard_buckets:0 > > state:DELETE_ONLY direction:ADD mutation_id:1 rollback:false > next_mutation_id:2 format_version:3 state:PUBLIC offline_reason:"" view_query:"" mutationJobs:<...> drop_time:0 replacement_of:<id:0 time:<> > audit_mode:DISABLED drop_job_id:0 create_query:"" create_as_of_time:<wall_time:... > temporary:false >
    71  exec stmt  rows affected: 0
    72  
    73  statement ok
    74  SET tracing = on,kv,results; INSERT INTO t.kv(k, v) VALUES (1,2); SET tracing = off
    75  
    76  query TT
    77  SELECT operation, message FROM [SHOW KV TRACE FOR SESSION]
    78   WHERE operation != 'dist sender send'
    79  ----
    80  flow                                  CPut /Table/54/1/1/0 -> /TUPLE/2:2:Int/2
    81  flow                                  InitPut /Table/54/2/2/0 -> /BYTES/0x89
    82  kv.DistSender: sending partial batch  r28: sending batch 1 CPut, 1 EndTxn to (n1,s1):1
    83  flow                                  fast path completed
    84  exec stmt                             rows affected: 1
    85  
    86  
    87  statement error duplicate key value
    88  SET tracing = on,kv,results; INSERT INTO t.kv(k, v) VALUES (1,2); SET tracing = off
    89  
    90  query TT
    91  set tracing=off;
    92  SELECT operation, message FROM [SHOW KV TRACE FOR SESSION]
    93   WHERE operation != 'dist sender send'
    94  ----
    95  flow                                  CPut /Table/54/1/1/0 -> /TUPLE/2:2:Int/2
    96  flow                                  InitPut /Table/54/2/2/0 -> /BYTES/0x89
    97  kv.DistSender: sending partial batch  r28: sending batch 1 CPut, 1 EndTxn to (n1,s1):1
    98  exec stmt                             execution failed after 0 rows: duplicate key value (k)=(1) violates unique constraint "primary"
    99  
   100  statement error duplicate key value
   101  SET tracing = on,kv,results; INSERT INTO t.kv(k, v) VALUES (2,2); SET tracing = off
   102  
   103  query TT
   104  set tracing=off;
   105  SELECT operation, message FROM [SHOW KV TRACE FOR SESSION]
   106   WHERE operation != 'dist sender send'
   107  ----
   108  flow                                  CPut /Table/54/1/2/0 -> /TUPLE/2:2:Int/2
   109  flow                                  InitPut /Table/54/2/2/0 -> /BYTES/0x8a
   110  kv.DistSender: sending partial batch  r28: sending batch 1 CPut, 1 EndTxn to (n1,s1):1
   111  exec stmt                             execution failed after 0 rows: duplicate key value (v)=(2) violates unique constraint "woo"
   112  
   113  statement ok
   114  SET tracing = on,kv,results; CREATE TABLE t.kv2 AS TABLE t.kv; SET tracing = off
   115  
   116  query TT
   117  SELECT operation, regexp_replace(regexp_replace(regexp_replace(message, 'wall_time:\d+', 'wall_time:...'), 'wall_time:\d+', 'wall_time:...'), '\d\d\d\d\d+', '...PK...') as message
   118    FROM [SHOW KV TRACE FOR SESSION]
   119  WHERE message NOT LIKE '%Z/%'
   120    AND operation NOT LIKE 'kv.DistSender: sending partial batch%'  -- order of partial batches is not deterministic
   121    AND message NOT SIMILAR TO '%(PushTxn|ResolveIntent|SystemConfigSpan)%'
   122    AND tag NOT LIKE '%intExec=%'
   123    AND tag NOT LIKE '%scExec%'
   124    AND tag NOT LIKE '%IndexBackfiller%'
   125    AND operation != 'dist sender send'
   126  ----
   127  table reader  Scan /Table/54/{1-2}
   128  flow          CPut /NamespaceTable/30/1/53/29/"kv2"/4/1 -> 55
   129  flow          CPut /Table/3/1/55/2/1 -> table:<name:"kv2" id:55 parent_id:53 unexposed_parent_schema_id:29 version:1 modification_time:<> columns:<name:"k" id:1 type:<InternalType:<family:IntFamily width:64 precision:0 locale:"" visible_type:0 oid:20 time_precision_is_set:false > > nullable:true hidden:false > columns:<name:"v" id:2 type:<InternalType:<family:IntFamily width:64 precision:0 locale:"" visible_type:0 oid:20 time_precision_is_set:false > > nullable:true hidden:false > columns:<name:"rowid" id:3 type:<InternalType:<family:IntFamily width:64 precision:0 locale:"" visible_type:0 oid:20 time_precision_is_set:false > > nullable:false default_expr:"unique_rowid()" hidden:true > next_column_id:4 families:<name:"primary" id:0 column_names:"k" column_names:"v" column_names:"rowid" column_ids:1 column_ids:2 column_ids:3 default_column_id:0 > next_family_id:1 primary_index:<name:"primary" id:1 unique:true version:0 column_names:"rowid" column_directions:ASC column_ids:3 foreign_key:<table:0 index:0 name:"" validity:Validated shared_prefix_len:0 on_delete:NO_ACTION on_update:NO_ACTION match:SIMPLE > interleave:<> partitioning:<num_columns:0 > type:FORWARD created_explicitly:false encoding_type:0 sharded:<is_sharded:false name:"" shard_buckets:0 > > next_index_id:2 privileges:<users:<user:"admin" privileges:2 > users:<user:"root" privileges:2 > > next_mutation_id:1 format_version:3 state:ADD offline_reason:"" view_query:"" drop_time:0 replacement_of:<id:0 time:<> > audit_mode:DISABLED drop_job_id:0 create_query:"TABLE t.public.kv" create_as_of_time:<> temporary:false >
   130  exec stmt     rows affected: 0
   131  
   132  statement ok
   133  SET tracing = on,kv,results; UPDATE t.kv2 SET v = v + 2; SET tracing = off
   134  
   135  query TT
   136  SELECT operation, message
   137    FROM [SHOW KV TRACE FOR SESSION]
   138  WHERE message NOT LIKE '%Z/%'
   139    AND message NOT SIMILAR TO '%(PushTxn|ResolveIntent|SystemConfigSpan)%'
   140    AND tag NOT LIKE '%intExec=%'
   141    AND tag NOT LIKE '%scExec%'
   142    AND tag NOT LIKE '%IndexBackfiller%'
   143    AND operation != 'dist sender send'
   144  ----
   145  table reader                                             Scan /Table/55/{1-2}
   146  table reader                                             fetched: /kv2/primary/-9222809086901354496/k/v -> /1/2
   147  flow                                                     Put /Table/55/1/-9222809086901354496/0 -> /TUPLE/1:1:Int/1/1:2:Int/4
   148  flow                                                     fast path completed
   149  exec stmt                                                rows affected: 1
   150  
   151  statement ok
   152  SET tracing = on,kv,results; DELETE FROM t.kv2; SET tracing = off
   153  
   154  query TT
   155  SELECT operation, message FROM [SHOW KV TRACE FOR SESSION]
   156   WHERE operation != 'dist sender send'
   157  ----
   158  flow       DelRange /Table/55/1 - /Table/55/2
   159  flow       fast path completed
   160  exec stmt  rows affected: 1
   161  
   162  statement ok
   163  SET tracing = on,kv,results; DROP TABLE t.kv2; SET tracing = off
   164  
   165  query TT
   166  SELECT operation,
   167         regexp_replace(regexp_replace(regexp_replace(regexp_replace(message, 'wall_time:\d+', 'wall_time:...'), 'drop_job_id:[1-9]\d*', 'drop_job_id:...'), 'wall_time:\d+', 'wall_time:...'), 'drop_time:\d+', 'drop_time:...') as message
   168    FROM [SHOW KV TRACE FOR SESSION]
   169  WHERE message NOT LIKE '%Z/%' AND message NOT LIKE 'querying next range at%'
   170    AND operation NOT LIKE 'kv.DistSender: sending partial batch%'  -- order of partial batches is not deterministic
   171    AND message NOT SIMILAR TO '%(PushTxn|ResolveIntent|SystemConfigSpan)%'
   172    AND tag NOT LIKE '%intExec=%'
   173    AND tag NOT LIKE '%scExec%'
   174    AND tag NOT LIKE '%IndexBackfiller%'
   175    AND operation != 'dist sender send'
   176  ----
   177  flow       Put /Table/3/1/55/2/1 -> table:<name:"kv2" id:55 parent_id:53 unexposed_parent_schema_id:29 version:3 modification_time:<> columns:<name:"k" id:1 type:<InternalType:<family:IntFamily width:64 precision:0 locale:"" visible_type:0 oid:20 time_precision_is_set:false > > nullable:true hidden:false > columns:<name:"v" id:2 type:<InternalType:<family:IntFamily width:64 precision:0 locale:"" visible_type:0 oid:20 time_precision_is_set:false > > nullable:true hidden:false > columns:<name:"rowid" id:3 type:<InternalType:<family:IntFamily width:64 precision:0 locale:"" visible_type:0 oid:20 time_precision_is_set:false > > nullable:false default_expr:"unique_rowid()" hidden:true > next_column_id:4 families:<name:"primary" id:0 column_names:"k" column_names:"v" column_names:"rowid" column_ids:1 column_ids:2 column_ids:3 default_column_id:0 > next_family_id:1 primary_index:<name:"primary" id:1 unique:true version:0 column_names:"rowid" column_directions:ASC column_ids:3 foreign_key:<table:0 index:0 name:"" validity:Validated shared_prefix_len:0 on_delete:NO_ACTION on_update:NO_ACTION match:SIMPLE > interleave:<> partitioning:<num_columns:0 > type:FORWARD created_explicitly:false encoding_type:0 sharded:<is_sharded:false name:"" shard_buckets:0 > > next_index_id:2 privileges:<users:<user:"admin" privileges:2 > users:<user:"root" privileges:2 > > next_mutation_id:1 format_version:3 state:DROP offline_reason:"" draining_names:<parent_id:53 parent_schema_id:29 name:"kv2" > view_query:"" drop_time:... replacement_of:<id:0 time:<> > audit_mode:DISABLED drop_job_id:... create_query:"TABLE t.public.kv" create_as_of_time:<wall_time:... > temporary:false >
   178  exec stmt  rows affected: 0
   179  
   180  statement ok
   181  SET tracing = on,kv,results; DELETE FROM t.kv; SET tracing = off
   182  
   183  query TT
   184  SELECT operation, message FROM [SHOW KV TRACE FOR SESSION]
   185   WHERE operation != 'dist sender send'
   186  ----
   187  table reader                          Scan /Table/54/{1-2}
   188  table reader                          fetched: /kv/primary/1/v -> /2
   189  flow                                  Del /Table/54/2/2/0
   190  flow                                  Del /Table/54/1/1/0
   191  kv.DistSender: sending partial batch  r28: sending batch 1 Del to (n1,s1):1
   192  flow                                  fast path completed
   193  exec stmt                             rows affected: 1
   194  
   195  statement ok
   196  SET tracing = on,kv,results; DROP INDEX t.kv@woo CASCADE; SET tracing = off
   197  
   198  query TT
   199  SELECT operation,
   200         regexp_replace(regexp_replace(regexp_replace(message, 'wall_time:\d+', 'wall_time:...'), 'mutationJobs:<[^>]*>', 'mutationJobs:<...>'), 'wall_time:\d+', 'wall_time:...') as message
   201    FROM [SHOW KV TRACE FOR SESSION]
   202  WHERE message NOT LIKE '%Z/%' AND message NOT LIKE 'querying next range at%'
   203    AND operation NOT LIKE 'kv.DistSender: sending partial batch%'  -- order of partial batches is not deterministic
   204    /* since the transactions involved are multi-range, intent resolving is async and
   205    sometimes there's still intents around */
   206    AND message NOT SIMILAR TO '%(PushTxn|ResolveIntent|SystemConfigSpan)%'
   207    AND tag NOT LIKE '%intExec=%'
   208    AND tag NOT LIKE '%scExec%'
   209    AND tag NOT LIKE '%IndexBackfiller%'
   210    AND operation != 'dist sender send'
   211  ----
   212  flow       Put /Table/3/1/54/2/1 -> table:<name:"kv" id:54 parent_id:53 unexposed_parent_schema_id:29 version:5 modification_time:<> columns:<name:"k" id:1 type:<InternalType:<family:IntFamily width:64 precision:0 locale:"" visible_type:0 oid:20 time_precision_is_set:false > > nullable:false hidden:false > columns:<name:"v" id:2 type:<InternalType:<family:IntFamily width:64 precision:0 locale:"" visible_type:0 oid:20 time_precision_is_set:false > > nullable:true hidden:false > next_column_id:3 families:<name:"primary" id:0 column_names:"k" column_names:"v" column_ids:1 column_ids:2 default_column_id:2 > next_family_id:1 primary_index:<name:"primary" id:1 unique:true version:1 column_names:"k" column_directions:ASC column_ids:1 foreign_key:<table:0 index:0 name:"" validity:Validated shared_prefix_len:0 on_delete:NO_ACTION on_update:NO_ACTION match:SIMPLE > interleave:<> partitioning:<num_columns:0 > type:FORWARD created_explicitly:false encoding_type:0 sharded:<is_sharded:false name:"" shard_buckets:0 > > next_index_id:3 privileges:<users:<user:"admin" privileges:2 > users:<user:"root" privileges:2 > > mutations:<index:<name:"woo" id:2 unique:true version:1 column_names:"v" column_directions:ASC column_ids:2 extra_column_ids:1 foreign_key:<table:0 index:0 name:"" validity:Validated shared_prefix_len:0 on_delete:NO_ACTION on_update:NO_ACTION match:SIMPLE > interleave:<> partitioning:<num_columns:0 > type:FORWARD created_explicitly:true encoding_type:0 sharded:<is_sharded:false name:"" shard_buckets:0 > > state:DELETE_AND_WRITE_ONLY direction:DROP mutation_id:2 rollback:false > next_mutation_id:3 format_version:3 state:PUBLIC offline_reason:"" view_query:"" mutationJobs:<...> drop_time:0 replacement_of:<id:0 time:<> > audit_mode:DISABLED drop_job_id:0 create_query:"" create_as_of_time:<wall_time:... > temporary:false >
   213  exec stmt  rows affected: 0
   214  
   215  statement ok
   216  SET tracing = on,kv,results; DROP TABLE t.kv; SET tracing = off
   217  
   218  query TT
   219  SELECT operation, regexp_replace(regexp_replace(regexp_replace(regexp_replace(message, 'wall_time:\d+', 'wall_time:...'), 'job_id:[1-9]\d*', 'job_id:...', 'g'), 'wall_time:\d+', 'wall_time:...'), 'drop_time:\d+', 'drop_time:...', 'g') as message
   220    FROM [SHOW KV TRACE FOR SESSION]
   221  WHERE message NOT LIKE '%Z/%' AND message NOT LIKE 'querying next range at%'
   222    AND operation NOT LIKE 'kv.DistSender: sending partial batch%'  -- order of partial batches is not deterministic
   223    AND message NOT SIMILAR TO '%(PushTxn|ResolveIntent|SystemConfigSpan)%'
   224    AND tag NOT LIKE '%intExec=%'
   225    AND tag NOT LIKE '%scExec%'
   226    AND tag NOT LIKE '%IndexBackfiller%'
   227    AND operation != 'dist sender send'
   228  ----
   229  flow       Put /Table/3/1/54/2/1 -> table:<name:"kv" id:54 parent_id:53 unexposed_parent_schema_id:29 version:8 modification_time:<> columns:<name:"k" id:1 type:<InternalType:<family:IntFamily width:64 precision:0 locale:"" visible_type:0 oid:20 time_precision_is_set:false > > nullable:false hidden:false > columns:<name:"v" id:2 type:<InternalType:<family:IntFamily width:64 precision:0 locale:"" visible_type:0 oid:20 time_precision_is_set:false > > nullable:true hidden:false > next_column_id:3 families:<name:"primary" id:0 column_names:"k" column_names:"v" column_ids:1 column_ids:2 default_column_id:2 > next_family_id:1 primary_index:<name:"primary" id:1 unique:true version:1 column_names:"k" column_directions:ASC column_ids:1 foreign_key:<table:0 index:0 name:"" validity:Validated shared_prefix_len:0 on_delete:NO_ACTION on_update:NO_ACTION match:SIMPLE > interleave:<> partitioning:<num_columns:0 > type:FORWARD created_explicitly:false encoding_type:0 sharded:<is_sharded:false name:"" shard_buckets:0 > > next_index_id:3 privileges:<users:<user:"admin" privileges:2 > users:<user:"root" privileges:2 > > next_mutation_id:3 format_version:3 state:DROP offline_reason:"" draining_names:<parent_id:53 parent_schema_id:29 name:"kv" > view_query:"" drop_time:... replacement_of:<id:0 time:<> > audit_mode:DISABLED drop_job_id:... gc_mutations:<index_id:2 drop_time:... job_id:... > create_query:"" create_as_of_time:<wall_time:... > temporary:false >
   230  exec stmt  rows affected: 0
   231  
   232  # Check that session tracing does not inhibit the fast path for inserts &
   233  # friends (the path resulting in 1PC transactions).
   234  
   235  subtest autocommit
   236  
   237  statement ok
   238  CREATE TABLE t.kv3(k INT PRIMARY KEY, v INT, FAMILY "primary" (k, v))
   239  
   240  statement ok
   241  SET tracing = on; INSERT INTO t.kv3 (k, v) VALUES (1,1); SET tracing = off
   242  
   243  # We look for rows containing an EndTxn as proof that the
   244  # insertNode is committing the txn.
   245  query T
   246  SELECT message FROM [SHOW TRACE FOR SESSION] WHERE message LIKE e'%1 CPut, 1 EndTxn%' AND message NOT LIKE e'%proposing command%'
   247  ----
   248  r29: sending batch 1 CPut, 1 EndTxn to (n1,s1):1
   249  1 CPut, 1 EndTxn
   250  
   251  ## TODO(tschottdorf): re-enable
   252  # statement ok
   253  # CREATE TABLE t.enginestats(k INT PRIMARY KEY, v INT)
   254  #
   255  # statement ok
   256  # SHOW TRACE FOR SELECT * FROM t.enginestats
   257  #
   258  # query T
   259  # SELECT message FROM [ SHOW TRACE FOR SESSION ] WHERE message LIKE '%InternalDelete%'
   260  # ----
   261  # engine stats: {InternalDeleteSkippedCount:0 TimeBoundNumSSTs:0}
   262  
   263  # Check that we can run set tracing regardless of the current tracing state.
   264  # This is convenient; sometimes it's unclear, for example, if you previously
   265  # stopped tracing or not, so issuing a set tracing=off should just work.
   266  subtest idempotent
   267  
   268  statement ok
   269  SET tracing = on; SET tracing = on;
   270  
   271  statement ok
   272  SET tracing = off; SET tracing = off;
   273  
   274  # Check that we can run set tracing in the aborted state (this is implemented by
   275  # making set tracing an ObserverStmt). This is very convenient for clients that
   276  # start tracing, then might get an error, then want to stop tracing.
   277  subtest aborted_txn
   278  
   279  query error pq: foo
   280  BEGIN; SELECT crdb_internal.force_error('', 'foo')
   281  
   282  statement ok
   283  SET tracing = off
   284  
   285  statement ok
   286  ROLLBACK
   287  
   288  subtest replica
   289  
   290  statement ok
   291  CREATE TABLE t (a INT PRIMARY KEY)
   292  
   293  statement ok
   294  SET tracing = on; SELECT * FROM t; SET tracing = off
   295  
   296  # Temporarily disabled flaky test (#43043).
   297  # query III colnames
   298  # SELECT DISTINCT node_id, store_id, replica_id
   299  #   FROM [SHOW EXPERIMENTAL_REPLICA TRACE FOR SESSION]
   300  # ----
   301  # node_id  store_id  replica_id
   302  # 1        1         26
   303  # 1        1         6
   304  # 1        1         29
   305  
   306  subtest system_table_lookup
   307  
   308  # We use AOST to bypass the table cache.
   309  statement ok
   310  SET tracing = on,kv; SELECT * FROM system.eventlog AS OF SYSTEM TIME '-1us'; SET tracing = off
   311  
   312  query TT
   313  SELECT operation, regexp_replace(regexp_replace(regexp_replace(message, 'job_id:[1-9]\d*', 'job_id:...', 'g'), 'wall_time:\d+', 'wall_time:...'), 'drop_time:\d+', 'drop_time:...', 'g') as message
   314    FROM [SHOW KV TRACE FOR SESSION]
   315  WHERE (message LIKE 'querying next range%' OR message LIKE '%batch%')
   316    AND message NOT LIKE '%SystemConfigSpan%'
   317    AND message NOT LIKE '%PushTxn%'
   318  ----
   319  dist sender send  querying next range at /NamespaceTable/30/1/0/0/"test"/4/1
   320  dist sender send  r26: sending batch 1 Get to (n1,s1):1
   321  dist sender send  querying next range at /NamespaceTable/30/1/52/0/"system"/4/1
   322  dist sender send  r26: sending batch 1 Get to (n1,s1):1
   323  dist sender send  querying next range at /Table/3/1/12/2/1
   324  dist sender send  r6: sending batch 1 Get to (n1,s1):1
   325  dist sender send  querying next range at /Table/3/1/1/2/1
   326  dist sender send  r6: sending batch 1 Get to (n1,s1):1
   327  dist sender send  querying next range at /Table/12/1
   328  dist sender send  r8: sending batch 1 Scan to (n1,s1):1