Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

sql: prepared statement with AS OF SYSTEM TIME can create txn atomicity violation #68216

Closed
nvanbenschoten opened this issue Jul 29, 2021 · 6 comments
Labels
A-sql-executor SQL txn logic C-bug Code not up to spec/doc, specs & docs deemed correct. Solution expected to change code/behavior. T-sql-queries SQL Queries Team

Comments

@nvanbenschoten
Copy link
Member

nvanbenschoten commented Jul 29, 2021

In 078c58a, we added an assertion that transaction timestamps are not manually set using the (*Txn).SetFixedTimestamp API after a transaction has already been used. This would be very unsafe, as it would allow transactions to silently change timestamps and violate atomicity. It turns out that we do hit this assertion, which revealed that something was wrong.

The good news is that even without the assertion, we don't seem to be silently violating atomicity in these cases, as another assertion in KV notices the changed txn timestamp. The bad news is that this is possible to hit thanks to the unchecked use of SetFixedTimestamp during statement preparation.

> create table t (x int);
CREATE TABLE
> insert into t values (1);
INSERT 1
> select crdb_internal_mvcc_timestamp, * from t;
   crdb_internal_mvcc_timestamp  | x
---------------------------------+----
  1627526754922910000.0000000000 | 1
(1 row)
> begin as of system time (1627526754922910000.0000000000-1)::string;
BEGIN
  OPEN> select * from t;
  x
-----
(0 rows)
  OPEN> prepare y as select * from t as of system time 1627526754922910000.0000000000;
PREPARE
  OPEN> select * from t;
ERROR: internal error: unexpected batch read timestamp: 1627526754.922910000,0. Expected refreshed timestamp: 1627526754.922909999,0. ba: Scan [/Table/59/1,/Table/59/2), [txn: ad8d53e5]. txn: "sql txn" meta={id=ad8d53e5 pri=0.03468194 epo=0 ts=1627526754.922910000,0 min=1627526754.922909999,0 seq=0} lock=false stat=PENDING rts=1627526754.922910000,0 wto=false gul=1627526754.922910000,0
SQLSTATE: XX000
DETAIL: stack trace:
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_span_refresher.go:160: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_pipeliner.go:285: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_seq_num_allocator.go:105: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_heartbeater.go:240: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_coord_sender.go:513: Send()
github.com/cockroachdb/cockroach/pkg/kv/db.go:831: sendUsingSender()
github.com/cockroachdb/cockroach/pkg/kv/txn.go:982: Send()
github.com/cockroachdb/cockroach/pkg/sql/row/kv_batch_fetcher.go:224: func1()
github.com/cockroachdb/cockroach/pkg/sql/row/kv_batch_fetcher.go:443: fetch()
github.com/cockroachdb/cockroach/pkg/sql/row/kv_batch_fetcher.go:589: nextBatch()
github.com/cockroachdb/cockroach/pkg/sql/row/kv_fetcher.go:147: NextKV()
github.com/cockroachdb/cockroach/pkg/sql/colfetcher/cfetcher.go:839: nextBatch()
github.com/cockroachdb/cockroach/pkg/sql/colfetcher/cfetcher.go:798: nextAdapter()
github.com/cockroachdb/cockroach/pkg/sql/colmem/allocator.go:299: PerformOperation()
github.com/cockroachdb/cockroach/pkg/sql/colfetcher/cfetcher.go:790: NextBatch()
github.com/cockroachdb/cockroach/pkg/sql/colfetcher/colbatch_scan.go:97: Next()
github.com/cockroachdb/cockroach/pkg/sql/colexec/colexecutils/cancel_checker.go:59: Next()
github.com/cockroachdb/cockroach/pkg/sql/colexec/colexecbase/simple_project.go:125: Next()
github.com/cockroachdb/cockroach/pkg/sql/colflow/flow_coordinator.go:239: nextAdapter()
github.com/cockroachdb/cockroach/pkg/sql/colexecerror/error.go:91: CatchVectorizedRuntimeError()
github.com/cockroachdb/cockroach/pkg/sql/colflow/flow_coordinator.go:243: next()
github.com/cockroachdb/cockroach/pkg/sql/colflow/flow_coordinator.go:282: Run()
github.com/cockroachdb/cockroach/pkg/sql/colflow/vectorized_flow.go:257: Run()
github.com/cockroachdb/cockroach/pkg/sql/distsql_running.go:525: Run()
github.com/cockroachdb/cockroach/pkg/sql/distsql_running.go:1262: PlanAndRun()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_exec.go:1110: execWithDistSQLEngine()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_exec.go:972: dispatchToExecutionEngine()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_exec.go:690: execStmtInOpenState()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_exec.go:126: execStmt()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1625: func1()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1627: execCmd()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1549: run()

Jira issue: CRDB-8932

@nvanbenschoten nvanbenschoten added C-bug Code not up to spec/doc, specs & docs deemed correct. Solution expected to change code/behavior. A-sql-executor SQL txn logic labels Jul 29, 2021
@blathers-crl blathers-crl bot added the T-sql-queries SQL Queries Team label Jul 29, 2021
nvanbenschoten added a commit to nvanbenschoten/cockroach that referenced this issue Jul 29, 2021
Related to cockroachdb#68216.

Previously, running `crdb_internal.show_create_all_tables` in an
existing explicit transaction would crash for the reasons discussed
in cockroachdb#68216. This should not have crashed, but this also revealed that
the internal executor in the `showCreateAllTablesGenerator` was a little
confused. It was issuing AS OF SYSTEM TIME queries, but also supplying
its parent transaction. So it wanted to execute in the context of its
parent transaction, but also to run at a very specific timestamp -
contradictory desires.

This commit fixes this by removing the transactions from these uses of
the internal executor and letting the internal executor queries run at
their fixed timestamp.

An alternative to this is to do away with the non-transactional nature
of `showCreateAllTablesGenerator`. I don't understand why it is using
its own timestamp and issuing AS OF SYSTEM TIME queries at all, instead
of just using its parent transaction. But this all seems so deliberate
that I imagine there was a good reason to build it this way.

Example crash:
```
➜ ./cockroach demo --insecure

> BEGIN;

OPEN> SELECT count(*) FROM rides;
  count
---------
    500

OPEN> SELECT crdb_internal.show_create_all_tables('movr');
ERROR: internal error: crdb_internal.show_create_all_tables: unexpected batch read timestamp: 1627529007.202325000,0. Expected refreshed timestamp: 1627528898.793460000,0. ba: Scan [/Table/3/1,/Table/3/2), [txn: 3565aed1]. txn: "sql txn" meta={id=3565aed1 pri=0.05136598 epo=0 ts=1627529007.202325000,0 min=1627528898.793460000,0 seq=0} lock=false stat=PENDING rts=1627529007.202325000,0 wto=false gul=1627529007.202325000,0
SQLSTATE: XX000
DETAIL: stack trace:
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_span_refresher.go:160: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_pipeliner.go:285: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_seq_num_allocator.go:105: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_heartbeater.go:240: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_coord_sender.go:513: Send()
github.com/cockroachdb/cockroach/pkg/kv/db.go:831: sendUsingSender()
github.com/cockroachdb/cockroach/pkg/kv/txn.go:982: Send()
github.com/cockroachdb/cockroach/pkg/kv/db.go:742: sendAndFill()
github.com/cockroachdb/cockroach/pkg/kv/txn.go:635: Run()
github.com/cockroachdb/cockroach/pkg/sql/catalog/catalogkv/catalogkv.go:281: getAllDescriptorsAndMaybeNamespaceEntriesUnvalidated()
github.com/cockroachdb/cockroach/pkg/sql/catalog/catalogkv/catalogkv.go:343: GetAllDescriptors()
github.com/cockroachdb/cockroach/pkg/sql/catalog/descs/kv_descriptors.go:265: getAllDescriptors()
github.com/cockroachdb/cockroach/pkg/sql/catalog/descs/collection.go:270: GetAllDescriptors()
github.com/cockroachdb/cockroach/pkg/sql/information_schema.go:2335: forEachTableDescWithTableLookupInternal()
github.com/cockroachdb/cockroach/pkg/sql/information_schema.go:2289: forEachTableDescWithTableLookup()
github.com/cockroachdb/cockroach/pkg/sql/pg_catalog.go:964: func1()
github.com/cockroachdb/cockroach/pkg/sql/virtual_schema.go:533: 1()
github.com/cockroachdb/cockroach/pkg/sql/virtual_table.go:120: func3()
github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:442: func2()
runtime/asm_amd64.s:1371: goexit()

HINT: You have encountered an unexpected error.

Please check the public issue tracker to check whether this problem is
already tracked. If you cannot find it there, please report the error
with details by creating a new issue.

If you would rather not post publicly, please contact us directly
using the support form.

We appreciate your feedback.
```
nvanbenschoten added a commit to nvanbenschoten/cockroach that referenced this issue Jul 29, 2021
Related to cockroachdb#68216.

Previously, running `crdb_internal.show_create_all_tables` in an
existing explicit transaction would crash for the reasons discussed
in cockroachdb#68216. This should not have crashed, but this also revealed that
the internal executor in the `showCreateAllTablesGenerator` was a little
confused. It was issuing AS OF SYSTEM TIME queries, but also supplying
its parent transaction. So it wanted to execute in the context of its
parent transaction, but also to run at a very specific timestamp -
contradictory desires.

This commit fixes this by removing the AS OF SYSTEM TIME clauses from
the internal executor queries. This has the effect of making this
builtin transactional.

Example crash:
```
➜ ./cockroach demo --insecure

> BEGIN;

OPEN> SELECT count(*) FROM rides;
  count
---------
    500

OPEN> SELECT crdb_internal.show_create_all_tables('movr');
ERROR: internal error: crdb_internal.show_create_all_tables: unexpected batch read timestamp: 1627529007.202325000,0. Expected refreshed timestamp: 1627528898.793460000,0. ba: Scan [/Table/3/1,/Table/3/2), [txn: 3565aed1]. txn: "sql txn" meta={id=3565aed1 pri=0.05136598 epo=0 ts=1627529007.202325000,0 min=1627528898.793460000,0 seq=0} lock=false stat=PENDING rts=1627529007.202325000,0 wto=false gul=1627529007.202325000,0
SQLSTATE: XX000
DETAIL: stack trace:
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_span_refresher.go:160: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_pipeliner.go:285: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_seq_num_allocator.go:105: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_heartbeater.go:240: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_coord_sender.go:513: Send()
github.com/cockroachdb/cockroach/pkg/kv/db.go:831: sendUsingSender()
github.com/cockroachdb/cockroach/pkg/kv/txn.go:982: Send()
github.com/cockroachdb/cockroach/pkg/kv/db.go:742: sendAndFill()
github.com/cockroachdb/cockroach/pkg/kv/txn.go:635: Run()
github.com/cockroachdb/cockroach/pkg/sql/catalog/catalogkv/catalogkv.go:281: getAllDescriptorsAndMaybeNamespaceEntriesUnvalidated()
github.com/cockroachdb/cockroach/pkg/sql/catalog/catalogkv/catalogkv.go:343: GetAllDescriptors()
github.com/cockroachdb/cockroach/pkg/sql/catalog/descs/kv_descriptors.go:265: getAllDescriptors()
github.com/cockroachdb/cockroach/pkg/sql/catalog/descs/collection.go:270: GetAllDescriptors()
github.com/cockroachdb/cockroach/pkg/sql/information_schema.go:2335: forEachTableDescWithTableLookupInternal()
github.com/cockroachdb/cockroach/pkg/sql/information_schema.go:2289: forEachTableDescWithTableLookup()
github.com/cockroachdb/cockroach/pkg/sql/pg_catalog.go:964: func1()
github.com/cockroachdb/cockroach/pkg/sql/virtual_schema.go:533: 1()
github.com/cockroachdb/cockroach/pkg/sql/virtual_table.go:120: func3()
github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:442: func2()
runtime/asm_amd64.s:1371: goexit()

HINT: You have encountered an unexpected error.

Please check the public issue tracker to check whether this problem is
already tracked. If you cannot find it there, please report the error
with details by creating a new issue.

If you would rather not post publicly, please contact us directly
using the support form.

We appreciate your feedback.
```
otan pushed a commit to otan-cockroach/cockroach that referenced this issue Jul 29, 2021
Related to cockroachdb#68216.

Previously, running `crdb_internal.show_create_all_tables` in an
existing explicit transaction would crash for the reasons discussed
in cockroachdb#68216. This should not have crashed, but this also revealed that
the internal executor in the `showCreateAllTablesGenerator` was a little
confused. It was issuing AS OF SYSTEM TIME queries, but also supplying
its parent transaction. So it wanted to execute in the context of its
parent transaction, but also to run at a very specific timestamp -
contradictory desires.

This commit fixes this by removing the transactions from these uses of
the internal executor and letting the internal executor queries run at
their fixed timestamp.

An alternative to this is to do away with the non-transactional nature
of `showCreateAllTablesGenerator`. I don't understand why it is using
its own timestamp and issuing AS OF SYSTEM TIME queries at all, instead
of just using its parent transaction. But this all seems so deliberate
that I imagine there was a good reason to build it this way.

Example crash:
```
➜ ./cockroach demo --insecure

> BEGIN;

OPEN> SELECT count(*) FROM rides;
  count
---------
    500

OPEN> SELECT crdb_internal.show_create_all_tables('movr');
ERROR: internal error: crdb_internal.show_create_all_tables: unexpected batch read timestamp: 1627529007.202325000,0. Expected refreshed timestamp: 1627528898.793460000,0. ba: Scan [/Table/3/1,/Table/3/2), [txn: 3565aed1]. txn: "sql txn" meta={id=3565aed1 pri=0.05136598 epo=0 ts=1627529007.202325000,0 min=1627528898.793460000,0 seq=0} lock=false stat=PENDING rts=1627529007.202325000,0 wto=false gul=1627529007.202325000,0
SQLSTATE: XX000
DETAIL: stack trace:
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_span_refresher.go:160: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_pipeliner.go:285: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_seq_num_allocator.go:105: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_heartbeater.go:240: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_coord_sender.go:513: Send()
github.com/cockroachdb/cockroach/pkg/kv/db.go:831: sendUsingSender()
github.com/cockroachdb/cockroach/pkg/kv/txn.go:982: Send()
github.com/cockroachdb/cockroach/pkg/kv/db.go:742: sendAndFill()
github.com/cockroachdb/cockroach/pkg/kv/txn.go:635: Run()
github.com/cockroachdb/cockroach/pkg/sql/catalog/catalogkv/catalogkv.go:281: getAllDescriptorsAndMaybeNamespaceEntriesUnvalidated()
github.com/cockroachdb/cockroach/pkg/sql/catalog/catalogkv/catalogkv.go:343: GetAllDescriptors()
github.com/cockroachdb/cockroach/pkg/sql/catalog/descs/kv_descriptors.go:265: getAllDescriptors()
github.com/cockroachdb/cockroach/pkg/sql/catalog/descs/collection.go:270: GetAllDescriptors()
github.com/cockroachdb/cockroach/pkg/sql/information_schema.go:2335: forEachTableDescWithTableLookupInternal()
github.com/cockroachdb/cockroach/pkg/sql/information_schema.go:2289: forEachTableDescWithTableLookup()
github.com/cockroachdb/cockroach/pkg/sql/pg_catalog.go:964: func1()
github.com/cockroachdb/cockroach/pkg/sql/virtual_schema.go:533: 1()
github.com/cockroachdb/cockroach/pkg/sql/virtual_table.go:120: func3()
github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:442: func2()
runtime/asm_amd64.s:1371: goexit()

HINT: You have encountered an unexpected error.

Please check the public issue tracker to check whether this problem is
already tracked. If you cannot find it there, please report the error
with details by creating a new issue.

If you would rather not post publicly, please contact us directly
using the support form.

We appreciate your feedback.
```
craig bot pushed a commit that referenced this issue Jul 30, 2021
68217: sql: fix show_create_all_tables in explicit transactions r=nvanbenschoten a=nvanbenschoten

Related to #68216.

Previously, running `crdb_internal.show_create_all_tables` in an existing explicit transaction would crash for the reasons discussed in #68216. This should not have crashed but it should have thrown an error. This revealed that the internal executor in the `showCreateAllTablesGenerator` was a little confused. It was issuing AS OF SYSTEM TIME queries, but also supplying its parent transaction. So it wanted to execute in the context of its parent transaction, but also to run at a very specific timestamp - contradictory desires.

This commit fixes this by removing the AS OF SYSTEM TIME clauses from the internal executor queries. This has the effect of making this builtin transactional.

Example crash:
```
➜ ./cockroach demo --insecure

> BEGIN;

OPEN> SELECT count(*) FROM rides;
  count
---------
    500

OPEN> SELECT crdb_internal.show_create_all_tables('movr');
ERROR: internal error: crdb_internal.show_create_all_tables: unexpected batch read timestamp: 1627529007.202325000,0. Expected refreshed timestamp: 1627528898.793460000,0. ba: Scan [/Table/3/1,/Table/3/2), [txn: 3565aed1]. txn: "sql txn" meta={id=3565aed1 pri=0.05136598 epo=0 ts=1627529007.202325000,0 min=1627528898.793460000,0 seq=0} lock=false stat=PENDING rts=1627529007.202325000,0 wto=false gul=1627529007.202325000,0
SQLSTATE: XX000
DETAIL: stack trace:
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_span_refresher.go:160: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_pipeliner.go:285: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_seq_num_allocator.go:105: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_interceptor_heartbeater.go:240: SendLocked()
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_coord_sender.go:513: Send()
github.com/cockroachdb/cockroach/pkg/kv/db.go:831: sendUsingSender()
github.com/cockroachdb/cockroach/pkg/kv/txn.go:982: Send()
github.com/cockroachdb/cockroach/pkg/kv/db.go:742: sendAndFill()
github.com/cockroachdb/cockroach/pkg/kv/txn.go:635: Run()
github.com/cockroachdb/cockroach/pkg/sql/catalog/catalogkv/catalogkv.go:281: getAllDescriptorsAndMaybeNamespaceEntriesUnvalidated()
github.com/cockroachdb/cockroach/pkg/sql/catalog/catalogkv/catalogkv.go:343: GetAllDescriptors()
github.com/cockroachdb/cockroach/pkg/sql/catalog/descs/kv_descriptors.go:265: getAllDescriptors()
github.com/cockroachdb/cockroach/pkg/sql/catalog/descs/collection.go:270: GetAllDescriptors()
github.com/cockroachdb/cockroach/pkg/sql/information_schema.go:2335: forEachTableDescWithTableLookupInternal()
github.com/cockroachdb/cockroach/pkg/sql/information_schema.go:2289: forEachTableDescWithTableLookup()
github.com/cockroachdb/cockroach/pkg/sql/pg_catalog.go:964: func1()
github.com/cockroachdb/cockroach/pkg/sql/virtual_schema.go:533: 1()
github.com/cockroachdb/cockroach/pkg/sql/virtual_table.go:120: func3()
github.com/cockroachdb/cockroach/pkg/util/stop/stopper.go:442: func2()
runtime/asm_amd64.s:1371: goexit()

HINT: You have encountered an unexpected error.

Please check the public issue tracker to check whether this problem is
already tracked. If you cannot find it there, please report the error
with details by creating a new issue.

If you would rather not post publicly, please contact us directly
using the support form.

We appreciate your feedback.
```

Co-authored-by: Nathan VanBenschoten <[email protected]>
nvanbenschoten added a commit to nvanbenschoten/cockroach that referenced this issue Aug 4, 2021
This commit asserts that a transaction has not been used to read or to
write by the time that `SetFixedTimestamp` is called on it.

This was extracted from cockroachdb#68194 and modified to return an error from
`SetFixedTimestamp` on misuse instead of fatal-ing. This provides a
sufficient, temporary backstop for cockroachdb#68216 until the conn executor logic
is fixed:

```
[email protected]:26257/movr> create table t (x int);
CREATE TABLE

[email protected]:26257/movr> insert into t values (1);
INSERT 1

[email protected]:26257/movr> select crdb_internal_mvcc_timestamp, * from t;
   crdb_internal_mvcc_timestamp  | x
---------------------------------+----
  1628094563935439000.0000000000 | 1
(1 row)

[email protected]:26257/movr> begin as of system time (1628094563935439000.0000000000-1)::string;
BEGIN

[email protected]:26257/movr  OPEN> select * from t;
  x
-----
(0 rows)

[email protected]:26257/movr  OPEN> prepare y as select * from t as of system time 1628094563935439000.0000000000;
ERROR: internal error: cannot set fixed timestamp, txn "sql txn" meta={id=e5e81c19 pri=0.01517572 epo=0 ts=1628094563.935438999,0 min=1628094563.935438999,0 seq=0} lock=false stat=PENDING rts=1628094563.935438999,0 wto=false gul=1628094563.935438999,0 already performed reads
SQLSTATE: XX000
DETAIL: stack trace:
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_coord_sender.go:1016: SetFixedTimestamp()
github.com/cockroachdb/cockroach/pkg/kv/txn.go:1200: SetFixedTimestamp()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_prepare.go:278: populatePrepared()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_prepare.go:220: func1()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_prepare.go:226: prepare()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_prepare.go:112: addPreparedStmt()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_exec.go:570: execStmtInOpenState()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_exec.go:126: execStmt()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1626: func1()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1628: execCmd()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1550: run()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:627: ServeConn()
github.com/cockroachdb/cockroach/pkg/sql/pgwire/conn.go:645: func1()
runtime/asm_amd64.s:1371: goexit()

HINT: You have encountered an unexpected error.

Please check the public issue tracker to check whether this problem is
already tracked. If you cannot find it there, please report the error
with details by creating a new issue.

If you would rather not post publicly, please contact us directly
using the support form.

We appreciate your feedback.

[email protected]:26257/? ERROR>
```
@nvanbenschoten
Copy link
Member Author

#68426 provides enough of a backstop for this so that it is no longer high severity.

nvanbenschoten added a commit to nvanbenschoten/cockroach that referenced this issue Aug 4, 2021
This commit asserts that a transaction has not been used to read or to
write by the time that `SetFixedTimestamp` is called on it.

This was extracted from cockroachdb#68194 and modified to return an error from
`SetFixedTimestamp` on misuse instead of fatal-ing. This provides a
sufficient, temporary backstop for cockroachdb#68216 until the conn executor logic
is fixed:

```
[email protected]:26257/movr> create table t (x int);
CREATE TABLE

[email protected]:26257/movr> insert into t values (1);
INSERT 1

[email protected]:26257/movr> select crdb_internal_mvcc_timestamp, * from t;
   crdb_internal_mvcc_timestamp  | x
---------------------------------+----
  1628094563935439000.0000000000 | 1
(1 row)

[email protected]:26257/movr> begin as of system time (1628094563935439000.0000000000-1)::string;
BEGIN

[email protected]:26257/movr  OPEN> select * from t;
  x
-----
(0 rows)

[email protected]:26257/movr  OPEN> prepare y as select * from t as of system time 1628094563935439000.0000000000;
ERROR: internal error: cannot set fixed timestamp, txn "sql txn" meta={id=e5e81c19 pri=0.01517572 epo=0 ts=1628094563.935438999,0 min=1628094563.935438999,0 seq=0} lock=false stat=PENDING rts=1628094563.935438999,0 wto=false gul=1628094563.935438999,0 already performed reads
SQLSTATE: XX000
DETAIL: stack trace:
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_coord_sender.go:1016: SetFixedTimestamp()
github.com/cockroachdb/cockroach/pkg/kv/txn.go:1200: SetFixedTimestamp()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_prepare.go:278: populatePrepared()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_prepare.go:220: func1()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_prepare.go:226: prepare()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_prepare.go:112: addPreparedStmt()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_exec.go:570: execStmtInOpenState()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_exec.go:126: execStmt()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1626: func1()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1628: execCmd()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1550: run()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:627: ServeConn()
github.com/cockroachdb/cockroach/pkg/sql/pgwire/conn.go:645: func1()
runtime/asm_amd64.s:1371: goexit()

HINT: You have encountered an unexpected error.

Please check the public issue tracker to check whether this problem is
already tracked. If you cannot find it there, please report the error
with details by creating a new issue.

If you would rather not post publicly, please contact us directly
using the support form.

We appreciate your feedback.

[email protected]:26257/? ERROR>
```
craig bot pushed a commit that referenced this issue Aug 5, 2021
67866: sql: implement SQL Stats flush logic r=Azhng a=Azhng

Previous PR: #67805
Next Chained PR: #67090

## First Commit

sql: remove `count` from stmt/txn stats system table

Previously, system.statement_statistics and
system.transaction_statistics table includes a `count` column
that corresponds to `roachpb.StatementStatistics.Count` and
`roachpb.TransactionStatistics.Count` fields respectively.
The objective for that column is to make
`INSERT ON CONFLICT DO UPDATE` style query easy. However,
since early prototyping have shown that
`INSERT ON CONFLICT DO UPDATE` style statement is quite inefficient,
the SQL Stats flush mechanism will be implemented using
separate queries INSERT and UPDATE statements.
This column is no longer userful and it would require special handling.
Removing this column simplifies the flush logic and removes the
need for special handlings.

Release note (sql change): count column is removed from
 system.statement_statistics and system.transaction_statistics
 tables.

## Second Commit

sql: implement persistedsqlstats flush logic

This commit implements the initial flush logic of the
persisted sql stats subsystem.

Release note: None

68426: kv: assert txn unused in SetFixedTimestamp r=nvanbenschoten a=nvanbenschoten

This commit asserts that a transaction has not been used to read or to
write by the time that `SetFixedTimestamp` is called on it.

This was extracted from #68194 and modified to return an error from
`SetFixedTimestamp` on misuse instead of fatal-ing. This provides a
sufficient, temporary backstop for #68216 until the conn executor logic
is fixed:

```
[email protected]:26257/movr> create table t (x int);
CREATE TABLE

[email protected]:26257/movr> insert into t values (1);
INSERT 1

[email protected]:26257/movr> select crdb_internal_mvcc_timestamp, * from t;
   crdb_internal_mvcc_timestamp  | x
---------------------------------+----
  1628094563935439000.0000000000 | 1
(1 row)

[email protected]:26257/movr> begin as of system time (1628094563935439000.0000000000-1)::string;
BEGIN

[email protected]:26257/movr  OPEN> select * from t;
  x
-----
(0 rows)

[email protected]:26257/movr  OPEN> prepare y as select * from t as of system time 1628094563935439000.0000000000;
ERROR: internal error: cannot set fixed timestamp, txn "sql txn" meta={id=e5e81c19 pri=0.01517572 epo=0 ts=1628094563.935438999,0 min=1628094563.935438999,0 seq=0} lock=false stat=PENDING rts=1628094563.935438999,0 wto=false gul=1628094563.935438999,0 already performed reads
SQLSTATE: XX000
DETAIL: stack trace:
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_coord_sender.go:1016: SetFixedTimestamp()
github.com/cockroachdb/cockroach/pkg/kv/txn.go:1200: SetFixedTimestamp()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_prepare.go:278: populatePrepared()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_prepare.go:220: func1()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_prepare.go:226: prepare()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_prepare.go:112: addPreparedStmt()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_exec.go:570: execStmtInOpenState()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_exec.go:126: execStmt()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1626: func1()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1628: execCmd()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1550: run()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:627: ServeConn()
github.com/cockroachdb/cockroach/pkg/sql/pgwire/conn.go:645: func1()
runtime/asm_amd64.s:1371: goexit()

HINT: You have encountered an unexpected error.

Please check the public issue tracker to check whether this problem is
already tracked. If you cannot find it there, please report the error
with details by creating a new issue.

If you would rather not post publicly, please contact us directly
using the support form.

We appreciate your feedback.

[email protected]:26257/? ERROR>
```

68442: kv: include RangeID in rangefeed goroutine stacks r=nvanbenschoten a=nvanbenschoten

This commit includes the RangeID in each of a rangefeed processor and
its registations' associated goroutine stacks. This is a cheap and easy
way to get better observability into the ranges that have active
rangefeeds. It also tells us where those goroutines are spending their
time.

This will also become easier to use in Go 1.17, which improved the
format of stack traces.

68443: parser: add VIRTUAL syntax to help r=RaduBerinde a=rafiss

Release note: None

Co-authored-by: Azhng <[email protected]>
Co-authored-by: Nathan VanBenschoten <[email protected]>
Co-authored-by: Rafi Shamim <[email protected]>
sajjadrizvi pushed a commit to sajjadrizvi/cockroach that referenced this issue Aug 10, 2021
This commit asserts that a transaction has not been used to read or to
write by the time that `SetFixedTimestamp` is called on it.

This was extracted from cockroachdb#68194 and modified to return an error from
`SetFixedTimestamp` on misuse instead of fatal-ing. This provides a
sufficient, temporary backstop for cockroachdb#68216 until the conn executor logic
is fixed:

```
[email protected]:26257/movr> create table t (x int);
CREATE TABLE

[email protected]:26257/movr> insert into t values (1);
INSERT 1

[email protected]:26257/movr> select crdb_internal_mvcc_timestamp, * from t;
   crdb_internal_mvcc_timestamp  | x
---------------------------------+----
  1628094563935439000.0000000000 | 1
(1 row)

[email protected]:26257/movr> begin as of system time (1628094563935439000.0000000000-1)::string;
BEGIN

[email protected]:26257/movr  OPEN> select * from t;
  x
-----
(0 rows)

[email protected]:26257/movr  OPEN> prepare y as select * from t as of system time 1628094563935439000.0000000000;
ERROR: internal error: cannot set fixed timestamp, txn "sql txn" meta={id=e5e81c19 pri=0.01517572 epo=0 ts=1628094563.935438999,0 min=1628094563.935438999,0 seq=0} lock=false stat=PENDING rts=1628094563.935438999,0 wto=false gul=1628094563.935438999,0 already performed reads
SQLSTATE: XX000
DETAIL: stack trace:
github.com/cockroachdb/cockroach/pkg/kv/kvclient/kvcoord/txn_coord_sender.go:1016: SetFixedTimestamp()
github.com/cockroachdb/cockroach/pkg/kv/txn.go:1200: SetFixedTimestamp()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_prepare.go:278: populatePrepared()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_prepare.go:220: func1()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_prepare.go:226: prepare()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_prepare.go:112: addPreparedStmt()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_exec.go:570: execStmtInOpenState()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor_exec.go:126: execStmt()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1626: func1()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1628: execCmd()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:1550: run()
github.com/cockroachdb/cockroach/pkg/sql/conn_executor.go:627: ServeConn()
github.com/cockroachdb/cockroach/pkg/sql/pgwire/conn.go:645: func1()
runtime/asm_amd64.s:1371: goexit()

HINT: You have encountered an unexpected error.

Please check the public issue tracker to check whether this problem is
already tracked. If you cannot find it there, please report the error
with details by creating a new issue.

If you would rather not post publicly, please contact us directly
using the support form.

We appreciate your feedback.

[email protected]:26257/? ERROR>
```
@michae2
Copy link
Collaborator

michae2 commented Aug 10, 2021

@nvanbenschoten We don't fully understand. Should we be disallowing prepared queries with AOST?

@nvanbenschoten
Copy link
Member Author

I don't think we should be disallowing prepared queries with AOST, but I also don't think I've fully wrapped my head around why we're setting a fixed timestamp on the active transaction when doing so. Is this because we use the transaction during planning of the prepared statement, and we need to plan the query with the correct schema immediately at prepare time, instead of at execution time?

Regardless of the reason, I think we need some kind of check like we have for query execution that prevents inconsistent AOST timestamps in explicit transactions:

if readTs := ex.state.getReadTimestamp(); asOf.Timestamp != readTs {
err = pgerror.Newf(pgcode.Syntax,
"inconsistent AS OF SYSTEM TIME timestamp; expected: %s", readTs)
err = errors.WithHint(err, "try SET TRANSACTION AS OF SYSTEM TIME")
return makeErrEvent(err)
}

As of #68426, we have that check, but it's in the form of an internal error.

@RaduBerinde
Copy link
Member

I'm not sure why we set it. Perhaps indeed the idea was that we want to use the schema as of that time (though we should be re-resolving all datasources so it's not a correctness issue). There is also the somewhat related issue of allowing the AOST value to be a placeholder #30955

@ajwerner
Copy link
Contributor

Indeed the idea is to resolve the schema as of that timestamp. I think maybe what we'd want to do is set it explicitly if that timestamp is an exact value and not set it to anything if the timestamp is one of the allowed function calls.

@rafiss
Copy link
Collaborator

rafiss commented Jun 7, 2022

I can't reproduce. I'm pretty sure 9fdb39b fixes this.

@rafiss rafiss closed this as completed Jun 7, 2022
@mgartner mgartner moved this to Done in SQL Queries Jul 24, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
A-sql-executor SQL txn logic C-bug Code not up to spec/doc, specs & docs deemed correct. Solution expected to change code/behavior. T-sql-queries SQL Queries Team
Projects
Archived in project
Development

No branches or pull requests

6 participants