Counting SQLite virtual machine operations#

When SQLite executes a query, it does so by executing a sequence of virtual machine operations.

There are mechanisms for cancelling a query after a specific number of these operations, to protect against long-running queries.

To work with those mechanisms, it’s useful to get a feel for how many operations different queries execute.

Thanks to tips on the SQLite forum I now know how to count these operations using the sqlite3 command line tool, using .stats vmstats to turn on display of that number after each query:

1
% sqlite3 fixtures.db
2
SQLite version 3.36.0 2021-06-18 18:58:49
3
Enter ".help" for usage hints.
4
sqlite> .stats vmstep
5
sqlite> select * from facetable;
6
1|2019-01-14 08:00:00|1|1|CA|1|Mission|["tag1", "tag2"]|[{"foo": "bar"}]|one
7
2|2019-01-14 08:00:00|1|1|CA|1|Dogpatch|["tag1", "tag3"]|[]|two
8
3|2019-01-14 08:00:00|1|1|CA|1|SOMA|[]|[]|
9
4|2019-01-14 08:00:00|1|1|CA|1|Tenderloin|[]|[]|
10
5|2019-01-15 08:00:00|1|1|CA|1|Bernal Heights|[]|[]|
11
6|2019-01-15 08:00:00|1|1|CA|1|Hayes Valley|[]|[]|
12
7|2019-01-15 08:00:00|1|1|CA|2|Hollywood|[]|[]|
13
8|2019-01-15 08:00:00|1|1|CA|2|Downtown|[]|[]|
14
9|2019-01-16 08:00:00|1|1|CA|2|Los Feliz|[]|[]|
15
10|2019-01-16 08:00:00|1|1|CA|2|Koreatown|[]|[]|
16
11|2019-01-16 08:00:00|1|1|MI|3|Downtown|[]|[]|
17
12|2019-01-17 08:00:00|1|1|MI|3|Greektown|[]|[]|
18
13|2019-01-17 08:00:00|1|1|MI|3|Corktown|[]|[]|
19
14|2019-01-17 08:00:00|1|1|MI|3|Mexicantown|[]|[]|
20
15|2019-01-17 08:00:00|2|0|MC|4|Arcadia Planitia|[]|[]|
21
VM-steps: 187
22
sqlite> select * from facetable limit 3;
23
1|2019-01-14 08:00:00|1|1|CA|1|Mission|["tag1", "tag2"]|[{"foo": "bar"}]|one
24
2|2019-01-14 08:00:00|1|1|CA|1|Dogpatch|["tag1", "tag3"]|[]|two
25
3|2019-01-14 08:00:00|1|1|CA|1|SOMA|[]|[]|
26
VM-steps: 46

Using .stats on shows a more detailed group of statistics about the query:

1
sqlite> .stats on
2
sqlite> select * from facetable limit 3;
3
1|2019-01-14 08:00:00|1|1|CA|1|Mission|["tag1", "tag2"]|[{"foo": "bar"}]|one
4
2|2019-01-14 08:00:00|1|1|CA|1|Dogpatch|["tag1", "tag3"]|[]|two
5
3|2019-01-14 08:00:00|1|1|CA|1|SOMA|[]|[]|
6
Memory Used:                         195520 (max 195776) bytes
7
Number of Outstanding Allocations:   525 (max 526)
8
Number of Pcache Overflow Bytes:     5696 (max 5696) bytes
9
Largest Allocation:                  122400 bytes
10
Largest Pcache Allocation:           4104 bytes
11
Lookaside Slots Used:                94 (max 122)
12
Successful lookaside attempts:       431
13
Lookaside failures due to size:      4
14
Lookaside failures due to OOM:       0
15
Pager Heap Usage:                    23008 bytes
16
Page cache hits:                     6
17
Page cache misses:                   4
18
Page cache writes:                   0
19
Page cache spills:                   0
20
Schema Heap Usage:                   25216 bytes
21
Statement Heap/Lookaside Usage:      15504 bytes
22
Fullscan Steps:                      2
23
Sort Operations:                     0
24
Autoindex Inserts:                   0
25
Virtual Machine Steps:               46
26
Reprepare operations:                0
27
Number of times run:                 1
28
Memory used by prepared stmt:        15504

There is also a sqlite_stmt virtual table (documented here) which can be enabled using a loadable module, but I have not yet managed to get this to compile and load into the Python sqlite3 environment.

Cancelling queries after a specified number of opcodes#

You can set an upper limit on the number of opcodes in the sqlite3 command line using .progress 100 --limit 1, as described here:

1
sqlite> .progress 100 --limit 1
2
sqlite> select * from facetable limit 3;
3
1|2019-01-14 08:00:00|1|1|CA|1|Mission|["tag1", "tag2"]|[{"foo": "bar"}]|one
4
2|2019-01-14 08:00:00|1|1|CA|1|Dogpatch|["tag1", "tag3"]|[]|two
5
3|2019-01-14 08:00:00|1|1|CA|1|SOMA|[]|[]|
6
sqlite> select * from facetable;
7
1|2019-01-14 08:00:00|1|1|CA|1|Mission|["tag1", "tag2"]|[{"foo": "bar"}]|one
8
2|2019-01-14 08:00:00|1|1|CA|1|Dogpatch|["tag1", "tag3"]|[]|two
9
3|2019-01-14 08:00:00|1|1|CA|1|SOMA|[]|[]|
10
4|2019-01-14 08:00:00|1|1|CA|1|Tenderloin|[]|[]|
11
5|2019-01-15 08:00:00|1|1|CA|1|Bernal Heights|[]|[]|
12
6|2019-01-15 08:00:00|1|1|CA|1|Hayes Valley|[]|[]|
13
7|2019-01-15 08:00:00|1|1|CA|2|Hollywood|[]|[]|
14
Progress limit reached (1)
15
Error: interrupted

In Python code this can be achieved like so:

1
conn.set_progress_handler(lambda: 1, 100)

This sets a progress handler which will be called after every 100 opcodes - but by returning 1 the handler causes the query to be cancelled:

1
>>> import sqlite3
2
>>> conn = sqlite3.connect("fixtures.db")
3
>>> conn.set_progress_handler(lambda: 1, 200)
4
>>> conn.execute("select * from facetable limit 3").rows()
5
# Outputs rows
6
>>> conn.execute("select * from facetable").fetchall()
7
Traceback (most recent call last):
8
  File "<stdin>", line 1, in <module>
9
sqlite3.OperationalError: interrupted

This didn’t exactly work how I expected - I had to change the number from 100 to 200 and I’m not sure why. But it illustrates the principle.