1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
|
<!DOCTYPE html>
<html class="writer-html5" lang="en" data-content_root="./">
<head>
<meta charset="utf-8" /><meta name="viewport" content="width=device-width, initial-scale=1" />
<meta name="viewport" content="width=device-width, initial-scale=1.0" />
<title>Execution and tracing — APSW 3.46.0.1 documentation</title>
<link rel="stylesheet" type="text/css" href="_static/pygments.css?v=72bcf2f2" />
<link rel="stylesheet" type="text/css" href="_static/css/theme.css?v=19f00094" />
<link rel="stylesheet" type="text/css" href="_static/apsw.css?v=3c7e2631" />
<link rel="shortcut icon" href="_static/favicon.ico"/>
<!--[if lt IE 9]>
<script src="_static/js/html5shiv.min.js"></script>
<![endif]-->
<script src="_static/jquery.js?v=5d32c60e"></script>
<script src="_static/_sphinx_javascript_frameworks_compat.js?v=2cd50e6c"></script>
<script src="_static/documentation_options.js?v=d98f5d2b"></script>
<script src="_static/doctools.js?v=9a2dae69"></script>
<script src="_static/sphinx_highlight.js?v=dc90522c"></script>
<script src="_static/js/theme.js"></script>
<link rel="author" title="About these documents" href="about.html" />
<link rel="index" title="Index" href="genindex.html" />
<link rel="search" title="Search" href="search.html" />
<link rel="copyright" title="Copyright" href="copyright.html" />
<link rel="next" title="DBAPI notes" href="dbapi.html" />
<link rel="prev" title="Exceptions and Errors" href="exceptions.html" />
</head>
<body class="wy-body-for-nav">
<div class="wy-grid-for-nav">
<nav data-toggle="wy-nav-shift" class="wy-nav-side">
<div class="wy-side-scroll">
<div class="wy-side-nav-search" >
<a href="index.html" class="icon icon-home">
APSW
<img src="_static/apswlogo.png" class="logo" alt="Logo"/>
</a>
<div class="version">
3.46.0.1
</div>
<div role="search">
<form id="rtd-search-form" class="wy-form" action="search.html" method="get">
<input type="text" name="q" placeholder="Search docs" aria-label="Search docs" />
<input type="hidden" name="check_keywords" value="yes" />
<input type="hidden" name="area" value="default" />
</form>
</div>
</div><div class="wy-menu wy-menu-vertical" data-spy="affix" role="navigation" aria-label="Navigation menu">
<ul class="current">
<li class="toctree-l1"><a class="reference internal" href="about.html">About</a></li>
<li class="toctree-l1"><a class="reference internal" href="tips.html">Tips</a></li>
<li class="toctree-l1"><a class="reference internal" href="example.html">Example/Tour</a></li>
<li class="toctree-l1"><a class="reference internal" href="install.html">Installation and customization</a></li>
<li class="toctree-l1"><a class="reference internal" href="extensions.html">Extensions</a></li>
<li class="toctree-l1"><a class="reference internal" href="apsw.html">APSW Module</a></li>
<li class="toctree-l1"><a class="reference internal" href="connection.html">Connections to a database</a></li>
<li class="toctree-l1"><a class="reference internal" href="cursor.html">Cursors (executing SQL)</a></li>
<li class="toctree-l1"><a class="reference internal" href="blob.html">Blob Input/Output</a></li>
<li class="toctree-l1"><a class="reference internal" href="backup.html">Backup</a></li>
<li class="toctree-l1"><a class="reference internal" href="vtable.html">Virtual Tables</a></li>
<li class="toctree-l1"><a class="reference internal" href="vfs.html">Virtual File System (VFS)</a></li>
<li class="toctree-l1"><a class="reference internal" href="shell.html">Shell</a></li>
<li class="toctree-l1"><a class="reference internal" href="bestpractice.html">Best Practice</a></li>
<li class="toctree-l1"><a class="reference internal" href="ext.html">Various interesting and useful bits of functionality</a></li>
<li class="toctree-l1"><a class="reference internal" href="exceptions.html">Exceptions and Errors</a></li>
<li class="toctree-l1 current"><a class="current reference internal" href="#">Execution and tracing</a><ul>
<li class="toctree-l2"><a class="reference internal" href="#execution-model">Execution model</a></li>
<li class="toctree-l2"><a class="reference internal" href="#multi-threading-and-re-entrancy">Multi-threading and re-entrancy</a></li>
<li class="toctree-l2"><a class="reference internal" href="#bit-hosts">64 bit hosts</a></li>
<li class="toctree-l2"><a class="reference internal" href="#statement-cache">Statement Cache</a></li>
<li class="toctree-l2"><a class="reference internal" href="#tracing">Tracing</a><ul>
<li class="toctree-l3"><a class="reference internal" href="#execution-tracer">Execution Tracer</a></li>
<li class="toctree-l3"><a class="reference internal" href="#row-tracer">Row Tracer</a></li>
</ul>
</li>
<li class="toctree-l2"><a class="reference internal" href="#apsw-trace">APSW Trace</a></li>
</ul>
</li>
<li class="toctree-l1"><a class="reference internal" href="dbapi.html">DBAPI notes</a></li>
<li class="toctree-l1"><a class="reference internal" href="pysqlite.html">sqlite3 module differences</a></li>
<li class="toctree-l1"><a class="reference internal" href="benchmarking.html">Benchmarking</a></li>
<li class="toctree-l1"><a class="reference internal" href="copyright.html">Copyright and License</a></li>
<li class="toctree-l1"><a class="reference internal" href="changes.html">Change History</a></li>
<li class="toctree-l1"><a class="reference internal" href="py-modindex.html">Module Index</a></li>
<li class="toctree-l1"><a class="reference internal" href="genindex.html">Index</a></li>
</ul>
</div>
</div>
</nav>
<section data-toggle="wy-nav-shift" class="wy-nav-content-wrap"><nav class="wy-nav-top" aria-label="Mobile navigation menu" >
<i data-toggle="wy-nav-top" class="fa fa-bars"></i>
<a href="index.html">APSW</a>
</nav>
<div class="wy-nav-content">
<div class="rst-content style-external-links">
<div role="navigation" aria-label="Page navigation">
<ul class="wy-breadcrumbs">
<li><a href="index.html" class="icon icon-home" aria-label="Home"></a></li>
<li class="breadcrumb-item active">Execution and tracing</li>
<li class="wy-breadcrumbs-aside">
<a href="_sources/execution.rst.txt" rel="nofollow"> View page source</a>
</li>
</ul><div class="rst-breadcrumbs-buttons" role="navigation" aria-label="Sequential page navigation">
<a href="exceptions.html" class="btn btn-neutral float-left" title="Exceptions and Errors" accesskey="p"><span class="fa fa-arrow-circle-left" aria-hidden="true"></span> Previous</a>
<a href="dbapi.html" class="btn btn-neutral float-right" title="DBAPI notes" accesskey="n">Next <span class="fa fa-arrow-circle-right" aria-hidden="true"></span></a>
</div>
<hr/>
</div>
<div role="main" class="document" itemscope="itemscope" itemtype="http://schema.org/Article">
<div itemprop="articleBody">
<section id="execution-and-tracing">
<h1>Execution and tracing<a class="headerlink" href="#execution-and-tracing" title="Link to this heading"></a></h1>
<section id="execution-model">
<span id="executionmodel"></span><h2>Execution model<a class="headerlink" href="#execution-model" title="Link to this heading"></a></h2>
<p>SQLite does execution in two steps. First a statement is prepared,
which verifies the syntax, tables and fields and converts the
statement into an internal representation. The prepared statement is
then run. Execution stops when a row is available, there is an error
or the statement is complete.</p>
<p>The <a class="reference internal" href="cursor.html#apsw.Cursor.execute" title="apsw.Cursor.execute"><code class="xref py py-meth docutils literal notranslate"><span class="pre">Cursor.execute()</span></code></a> method automatically does the preparing and
starts execution. If none of the statements return rows then execution
will go to the end. If a row is returned then you use the cursor as an
iterator. Execution will resume as necessary to return each result row.</p>
<p>However this means that if you don’t read the rows returned then the
rest of your statements won’t be executed. APSW will detect
unexecuted previous statements and generate an exception. For
example:</p>
<div class="highlight-default notranslate"><div class="highlight"><pre><span></span><span class="gp">>>> </span><span class="n">cursor</span><span class="o">.</span><span class="n">execute</span><span class="p">(</span><span class="s2">"select * from foo ; create table bar(x,y,z)"</span><span class="p">)</span>
<span class="gp">>>> </span><span class="n">cursor</span><span class="o">.</span><span class="n">execute</span><span class="p">(</span><span class="s2">"create table bam(x,y,z)"</span><span class="p">)</span>
<span class="gt">Traceback (most recent call last):</span>
File <span class="nb">"<stdin>"</span>, line <span class="m">1</span>, in <span class="n">?</span>
<span class="gr">apsw.IncompleteExecutionError</span>: <span class="n">Error: there are still remaining sql statements to execute</span>
</pre></div>
</div>
<p>Because I didn’t read the results of <code class="docutils literal notranslate"><span class="pre">select</span> <span class="pre">*</span> <span class="pre">from</span> <span class="pre">foo</span></code> then the
following create table command didn’t have a chance to get
executed. On the next execute that condition is detected and an
exception raised.</p>
</section>
<section id="multi-threading-and-re-entrancy">
<h2>Multi-threading and re-entrancy<a class="headerlink" href="#multi-threading-and-re-entrancy" title="Link to this heading"></a></h2>
<p>ASPW lets you use SQLite in multi-threaded programs and will let other
threads execute while SQLite is working. It checks at start that
SQLite was compiled in <a class="reference external" href="https://www.sqlite.org/threadsafe.html">threadsafe mode</a> which is the default. The
<a class="reference external" href="https://docs.python.org/3/glossary.html#term-global-interpreter-lock">GIL</a>
is released when when SQLite APIs are called, and re-acquired while
running any Python code.</p>
<p>You cannot use the same cursor object in multiple threads concurrently
to execute statements. APSW will detect this and raise an
<a class="reference internal" href="exceptions.html#apsw.ThreadingViolationError" title="apsw.ThreadingViolationError"><code class="xref py py-exc docutils literal notranslate"><span class="pre">ThreadingViolationError</span></code></a>. It is safe to use the object serially
(eg calling <a class="reference internal" href="cursor.html#apsw.Cursor.execute" title="apsw.Cursor.execute"><code class="xref py py-meth docutils literal notranslate"><span class="pre">Cursor.execute()</span></code></a> in one thread and iterator in
another. You also can’t do things like try to
<a class="reference internal" href="connection.html#apsw.Connection.close" title="apsw.Connection.close"><code class="xref py py-meth docutils literal notranslate"><span class="pre">close()</span></code></a> a Connection concurrently in two threads.</p>
<p>A cursor object can only be executing one query at a time. You cannot
issue a new query from inside a trace function or from a user defined
function or collation since these are called while executing a
query. You can however make new cursors and use those without
issue. You may want to remember the Connection object when you set
your trace or user defined functions.</p>
</section>
<section id="bit-hosts">
<h2>64 bit hosts<a class="headerlink" href="#bit-hosts" title="Link to this heading"></a></h2>
<p>APSW is tested and works correctly on 32 and 64 bit hosts.
SQLite is limited to 32 bit quantities for strings,
blobs, number of columns etc even when compiled for 64 bit.
You will get a <a class="reference internal" href="exceptions.html#apsw.TooBigError" title="apsw.TooBigError"><code class="xref py py-exc docutils literal notranslate"><span class="pre">TooBigError</span></code></a> if trying to use strings
and blobs larger than 1 gigabyte.</p>
</section>
<section id="statement-cache">
<span id="statementcache"></span><h2>Statement Cache<a class="headerlink" href="#statement-cache" title="Link to this heading"></a></h2>
<p>Each <a class="reference internal" href="connection.html#apsw.Connection" title="apsw.Connection"><code class="xref py py-class docutils literal notranslate"><span class="pre">Connection</span></code></a> maintains a cache mapping SQL queries to a
<a class="reference external" href="https://sqlite.org/c3ref/stmt.html">prepared statement</a> to avoid
the overhead of <a class="reference external" href="https://sqlite.org/c3ref/prepare.html">repreparing</a> queries that are executed
multiple times. This is a classic trade off using more memory to
reduce CPU consumption.</p>
<p>By default there are up to 100 entries in the cache. Once the cache
is full, the least recently used item is discarded to make space for
new items.</p>
<p>You should pick a larger cache size if you have more than 100 unique
queries that you run. For example if you have 101 different queries
you run in order then the cache will not help.</p>
<p>If you are using <a class="reference internal" href="connection.html#apsw.Connection.authorizer" title="apsw.Connection.authorizer"><code class="xref py py-attr docutils literal notranslate"><span class="pre">authorizers</span></code></a> then be
aware authorizer callback is only called while statements are being
prepared. You can <a class="reference internal" href="connection.html#apsw.Connection" title="apsw.Connection"><code class="xref py py-class docutils literal notranslate"><span class="pre">specify</span> <span class="pre">zero</span></code></a> which will
disable the statement cache completely, use use <cite>can_cache = False</cite>
flag to <cite>execute</cite>/<cite>executemany</cite>.</p>
</section>
<section id="tracing">
<span id="id1"></span><h2>Tracing<a class="headerlink" href="#tracing" title="Link to this heading"></a></h2>
<p>You can install tracers on <a class="reference internal" href="cursor.html#apsw.Cursor" title="apsw.Cursor"><code class="xref py py-class docutils literal notranslate"><span class="pre">cursors</span></code></a> or
<a class="reference internal" href="connection.html#apsw.Connection" title="apsw.Connection"><code class="xref py py-class docutils literal notranslate"><span class="pre">connections</span></code></a> as an easy way of seeing exactly
what gets executed and what is returned. The tracers can also abort
execution and cause different values to be returned. This is very
useful for diagnostics and testing without having to modify your main
code.</p>
<div class="admonition note">
<p class="admonition-title">Note</p>
<p>You cannot issue new execute statements against the cursor
your tracer was called from. If you would like to make more queries
in the tracer then do them from a new cursor object. For example:</p>
<div class="highlight-default notranslate"><div class="highlight"><pre><span></span><span class="k">def</span> <span class="nf">exec_tracer</span><span class="p">(</span><span class="n">cursor</span><span class="p">,</span> <span class="n">sql</span><span class="p">,</span> <span class="n">bindings</span><span class="p">):</span>
<span class="n">cursor</span><span class="o">.</span><span class="n">connection</span><span class="o">.</span><span class="n">cursor</span><span class="p">()</span><span class="o">.</span><span class="n">execute</span><span class="p">(</span><span class="s2">"insert into log values(?,?)"</span><span class="p">,</span> <span class="p">(</span><span class="n">sql</span><span class="p">,</span><span class="nb">str</span><span class="p">(</span><span class="n">bindings</span><span class="p">)))</span>
<span class="k">return</span> <span class="kc">True</span>
</pre></div>
</div>
</div>
<section id="execution-tracer">
<span id="executiontracer"></span><h3>Execution Tracer<a class="headerlink" href="#execution-tracer" title="Link to this heading"></a></h3>
<p>The execution tracer is called after an SQL statement has been
prepared. (ie syntax errors will have caused an exception during
preparation so you won’t see them with a tracer). It is called with
three arguments.</p>
<blockquote>
<div><dl class="simple">
<dt>cursor</dt><dd><p>The cursor executing the statement</p>
</dd>
<dt>sql</dt><dd><p>The SQL text being executed</p>
</dd>
<dt>bindings</dt><dd><p>The bindings being used. This may be <em>None</em>, a dictionary or
a tuple.</p>
</dd>
</dl>
</div></blockquote>
<p>If the tracer return value is False then execution is
aborted with an <a class="reference internal" href="exceptions.html#apsw.ExecTraceAbort" title="apsw.ExecTraceAbort"><code class="xref py py-exc docutils literal notranslate"><span class="pre">ExecTraceAbort</span></code></a> exception. See the
<a class="reference internal" href="example.html#example-exectrace"><span class="std std-ref">example</span></a>.</p>
<p>Execution tracers can be installed on a specific cursor by setting
<a class="reference internal" href="cursor.html#apsw.Cursor.exec_trace" title="apsw.Cursor.exec_trace"><code class="xref py py-attr docutils literal notranslate"><span class="pre">Cursor.exec_trace</span></code></a> or for all cursors by setting
<a class="reference internal" href="connection.html#apsw.Connection.exec_trace" title="apsw.Connection.exec_trace"><code class="xref py py-attr docutils literal notranslate"><span class="pre">Connection.exec_trace</span></code></a>, with the cursor tracer taking
priority.</p>
</section>
<section id="row-tracer">
<span id="rowtracer"></span><h3>Row Tracer<a class="headerlink" href="#row-tracer" title="Link to this heading"></a></h3>
<p>The row tracer is called before each row is returned. It is called with
two arguments.</p>
<blockquote>
<div><dl class="simple">
<dt>cursor</dt><dd><p>The cursor returning the row</p>
</dd>
<dt>row</dt><dd><p>A tuple of the values about to be returned</p>
</dd>
</dl>
</div></blockquote>
<p>Whatever you return from the tracer is what is actually returned to
the caller of <a class="reference internal" href="cursor.html#apsw.Cursor.execute" title="apsw.Cursor.execute"><code class="xref py py-meth docutils literal notranslate"><span class="pre">execute()</span></code></a>. If you return None then the
whole row is skipped. See the <a class="reference internal" href="example.html#example-rowtrace"><span class="std std-ref">example</span></a>.
They are useful for logging and testing.</p>
<p>Row tracers can be installed on a specific cursor by setting
<a class="reference internal" href="cursor.html#apsw.Cursor.row_trace" title="apsw.Cursor.row_trace"><code class="xref py py-attr docutils literal notranslate"><span class="pre">Cursor.row_trace</span></code></a> or for all cursors by setting
<a class="reference internal" href="connection.html#apsw.Connection.row_trace" title="apsw.Connection.row_trace"><code class="xref py py-attr docutils literal notranslate"><span class="pre">Connection.row_trace</span></code></a>, with the cursor tracer taking
priority.</p>
<p>If you want to convert types then see <a class="reference internal" href="ext.html#typeconversion"><span class="std std-ref">Converting types into and out of SQLite</span></a>.</p>
</section>
</section>
<section id="apsw-trace">
<span id="apswtrace"></span><h2>APSW Trace<a class="headerlink" href="#apsw-trace" title="Link to this heading"></a></h2>
<p>APSW includes a tracer that lets you easily trace SQL execution as
well as providing a summary report without modifying your code.</p>
<div class="highlight-console notranslate"><div class="highlight"><pre><span></span><span class="gp">$ </span>python3<span class="w"> </span>-m<span class="w"> </span>apsw.trace<span class="w"> </span><span class="o">[</span>apswtrace<span class="w"> </span>options<span class="o">]</span><span class="w"> </span>yourscript.py<span class="w"> </span><span class="o">[</span>your<span class="w"> </span>options<span class="o">]</span>
</pre></div>
</div>
<p>The following options are available:</p>
<div class="highlight-console notranslate"><div class="highlight"><pre><span></span><span class="gp">$ </span>python3<span class="w"> </span>-m<span class="w"> </span>apsw.trace<span class="w"> </span>--help
<span class="go">Usage: apswtrace.py [options] pythonscript.py [pythonscriptoptions]</span>
<span class="go">This script runs a Python program that uses APSW and reports on SQL queries</span>
<span class="go">without modifying the program. This is done by using connection_hooks and</span>
<span class="go">registering row and execution tracers. See APSW documentation for more</span>
<span class="go">details on the output.</span>
<span class="go">Options:</span>
<span class="go"> -h, --help show this help message and exit</span>
<span class="go"> -o OUTPUT, --output=OUTPUT</span>
<span class="go"> Where to send the output. Use a filename, a single</span>
<span class="go"> dash for stdout, or the words stdout and stderr.</span>
<span class="go"> [stdout]</span>
<span class="go"> -s, --sql Log SQL statements as they are executed. [False]</span>
<span class="go"> -r, --rows Log returned rows as they are returned (turns on sql).</span>
<span class="go"> [False]</span>
<span class="go"> -t, --timestamps Include timestamps in logging</span>
<span class="go"> -i, --thread Include thread id in logging</span>
<span class="go"> -l LENGTH, --length=LENGTH</span>
<span class="go"> Max amount of a string to print [30]</span>
<span class="go"> --no-report A summary report is normally generated at program</span>
<span class="go"> exit. This turns off the report and saves memory.</span>
<span class="go"> --report-items=N How many items to report in top lists [15]</span>
<span class="go"> --reports=REPORTS Which reports to show</span>
<span class="go"> [summary,popular,aggregate,individual]</span>
</pre></div>
</div>
<p>This is sample output with the following options: <strong>–sql</strong>,
<strong>–rows</strong>, <strong>–timestamps</strong>, <strong>–thread</strong></p>
<div class="highlight-text notranslate"><div class="highlight"><pre><span></span>1e0e5a0 0.152 7fccea8456e0 OPEN: ":memory:" unix READWRITE|CREATE
1f72ac0 0.161 7fccea8456e0 OPEN: "testdb" unix READWRITE|CREATE
1f6b8d0 0.162 7fccea8456e0 CURSORFROM: 1f72ac0 DB: "testdb"
1f6b8d0 0.162 7fccea8456e0 SQL: create table foo(x,y,z)
1f6b8d0 0.239 7fccea8456e0 CURSORFROM: 1f72ac0 DB: "testdb"
1f6b8d0 0.239 7fccea8456e0 SQL: insert into foo values(?,?,?) BINDINGS: ("kjfhgk", "gkjlfdhgjkhsdfkjg", "gklsdfjgkldfjhnbnvc,mnxb,mnxcv..")
1f6b8d0 0.242 7fccea8456e0 CURSORFROM: 1f72ac0 DB: "testdb"
1f6b8d0 0.242 7fccea8456e0 SQL: insert into foo values(?,?,?) BINDINGS: ("gdfklhj", ":gjkhgfdsgfd", "gjkfhgjkhdfkjh")
1f6b8d0 0.244 7fccea8456e0 CURSORFROM: 1f72ac0 DB: "testdb"
1f6b8d0 0.245 7fccea8456e0 SQL: insert into foo values(?,?,?) BINDINGS: ("gdfjkhg", "gkjlfd", "")
1f6b8d0 0.247 7fccea8456e0 CURSORFROM: 1f72ac0 DB: "testdb"
1f6b8d0 0.247 7fccea8456e0 SQL: insert into foo values(?,?,?) BINDINGS: (1, 2, 30)
1f6b8d0 0.257 7fccea8456e0 CURSORFROM: 1f72ac0 DB: "testdb"
1f6b8d0 0.257 7fccea8456e0 SQL: select longest(x,y,z) from foo
1f6b8d0 0.257 7fccea8456e0 ROW: ("gklsdfjgkldfjhnbnvc,mnxb,mnxcv..")
</pre></div>
</div>
<p>Each row starts with the following fields:</p>
<blockquote>
<div><dl class="simple">
<dt>id</dt><dd><p>This is the <a class="reference external" href="https://docs.python.org/3/library/functions.html#id">id</a> of the
<a class="reference internal" href="cursor.html#apsw.Cursor" title="apsw.Cursor"><code class="xref py py-class docutils literal notranslate"><span class="pre">Cursor</span></code></a> or <a class="reference internal" href="connection.html#apsw.Connection" title="apsw.Connection"><code class="xref py py-class docutils literal notranslate"><span class="pre">Connection</span></code></a>. You can easily <a class="reference external" href="https://en.wikipedia.org/wiki/Grep">filter</a> the log if you just want to
find out what happened on a specific cursor or connection.</p>
</dd>
<dt>timestamp</dt><dd><p>This is time since the program started in seconds</p>
</dd>
<dt>threadid</dt><dd><p>The unique <a class="reference external" href="https://docs.python.org/library/thread.html#thread.get_ident">thread identifier</a></p>
</dd>
</dl>
</div></blockquote>
<p>The remainder of the line has one of the following forms:</p>
<blockquote>
<div><dl class="simple">
<dt>OPEN: “dbname” vfs open_flags</dt><dd><p>A <a class="reference internal" href="connection.html#apsw.Connection" title="apsw.Connection"><code class="xref py py-class docutils literal notranslate"><span class="pre">Connection</span></code></a> has been opened. The <em>dbname</em> is the
filename exactly as given in the call to
<a class="reference internal" href="connection.html#apsw.Connection" title="apsw.Connection"><code class="xref py py-class docutils literal notranslate"><span class="pre">Connection</span></code></a>. <em>vfs</em> is the name of the <a class="reference internal" href="vfs.html#vfs"><span class="std std-ref">VFS</span></a>
used to open the database. <em>open_flags</em> is the set of <a class="reference internal" href="apsw.html#apsw.mapping_open_flags" title="apsw.mapping_open_flags"><code class="xref py py-data docutils literal notranslate"><span class="pre">flags</span></code></a> supplied with the leading <em>SQLITE_OPEN</em>
prefix omitted.</p>
</dd>
<dt>CURSORFROM: connectionid DB: “dbname”</dt><dd><p>A cursor has been allocated. The <em>id</em> at the beginning of this row
is of the new cursor. <em>connectionid</em> is the id of the Connection
it was created from. The <em>dbname</em> is provided for convenience.
This message is logged the first time a cursor issues a query.</p>
</dd>
<dt>SQL: query BINDINGS: bindings</dt><dd><p>A query was issued on a cursor.</p>
</dd>
<dt>ROW: row</dt><dd><p>A result row was returned by a cursor.</p>
</dd>
</dl>
</div></blockquote>
<p>A report is also generated by default. This is example output from
running the test suite. When calculating time for queries, your code
execution time is included as well. For example if your query
returned 10 rows and you slept for 1 second on reading each row then
the time for the query will be recorded as 10 seconds. Because you
can have multiple queries active at the same time, as well as across
multiple threads, the total processing time can be larger than the
program run time. The processing time is only recorded for queries
that have no results or where you read all the result rows.
Processing time also includes waiting time on busy connections.</p>
<blockquote>
<div><div class="highlight-text notranslate"><div class="highlight"><pre><span></span>APSW TRACE SUMMARY REPORT
Program run time 83.073 seconds
Total connections 1308
Total cursors 3082
Number of threads used for queries 21
Total queries 127973
Number of distinct queries 578
Number of rows returned 2369
Time spent processing queries 120.530 seconds
</pre></div>
</div>
</div></blockquote>
<p>This shows how many times each query was run.</p>
<blockquote>
<div><div class="highlight-text notranslate"><div class="highlight"><pre><span></span>MOST POPULAR QUERIES
121451 insert into foo values(?)
1220 insert into abc values(1,2,?)
1118 select x from foo
909 select timesten(x) from foo where x=? order by x
654 select * from foo
426 update t1 set b=b||a||b
146 begin
88 create table foo(x,y)
79 insert into foo values(1,2)
76 rollback
71 pragma locking_mode=exclusive
71 insert into t1 values(2, 'abcdefghijklmnopqrstuvwxyz')
71 insert into t1 values(1, 'abcdefghijklmnopqrstuvwxyz')
71 insert into t1 select 4-a, b from t2
71 insert into foo values(date('now'), date('now'))
</pre></div>
</div>
</div></blockquote>
<p>This shows how many times a query was run and the sum of the
processing times in seconds. The <code class="docutils literal notranslate"><span class="pre">begin</span> <span class="pre">immediate</span></code> query
illustrates how time spent busy waiting is included.</p>
<blockquote>
<div><div class="highlight-text notranslate"><div class="highlight"><pre><span></span>LONGEST RUNNING - AGGREGATE
413 94.305 select timesten(x) from foo where x=? order by x
120637 12.941 select * from foo
12 4.115 begin immediate
121449 2.179 insert into foo values(?)
1220 1.509 insert into abc values(1,2,?)
3 1.380 create index foo_x on foo(x)
426 0.715 update t1 set b=b||a||b
38 0.420 insert into foo values(?,?)
71 0.241 create table t1(a unique, b)
88 0.206 create table foo(x,y)
61 0.170 create table abc(a,b,c)
27 0.165 insert into foo values(?,?,?)
1 0.158 select row,x,snap(x) from foo
80 0.150 insert into foo values(1,2)
71 0.127 insert into foo values(date('now'), date('now'))
</pre></div>
</div>
</div></blockquote>
<p>This shows the longest running queries with time in seconds.</p>
<blockquote>
<div><div class="highlight-text notranslate"><div class="highlight"><pre><span></span>LONGEST RUNNING - INDIVIDUAL
3.001 begin immediate
1.377 create index foo_x on foo(x)
1.102 begin immediate
0.944 select timesten(x) from foo where x=? order by x
0.893 select timesten(x) from foo where x=? order by x
0.817 select timesten(x) from foo where x=? order by x
0.816 select timesten(x) from foo where x=? order by x
0.786 select timesten(x) from foo where x=? order by x
0.783 select timesten(x) from foo where x=? order by x
0.713 select timesten(x) from foo where x=? order by x
0.701 select timesten(x) from foo where x=? order by x
0.651 select timesten(x) from foo where x=? order by x
0.646 select timesten(x) from foo where x=? order by x
0.631 select timesten(x) from foo where x=? order by x
0.620 select timesten(x) from foo where x=? order by x
</pre></div>
</div>
</div></blockquote>
</section>
</section>
</div>
</div>
<footer><div class="rst-footer-buttons" role="navigation" aria-label="Footer">
<a href="exceptions.html" class="btn btn-neutral float-left" title="Exceptions and Errors" accesskey="p" rel="prev"><span class="fa fa-arrow-circle-left" aria-hidden="true"></span> Previous</a>
<a href="dbapi.html" class="btn btn-neutral float-right" title="DBAPI notes" accesskey="n" rel="next">Next <span class="fa fa-arrow-circle-right" aria-hidden="true"></span></a>
</div>
<hr/>
<div role="contentinfo">
<p>© <a href="copyright.html">Copyright</a> 2004-2024, Roger Binns <rogerb@rogerbinns.com>.
<span class="lastupdated">Last updated on Jun 16, 2024.
</span></p>
</div>
Built with <a href="https://www.sphinx-doc.org/">Sphinx</a> using a
<a href="https://github.com/readthedocs/sphinx_rtd_theme">theme</a>
provided by <a href="https://readthedocs.org">Read the Docs</a>.
</footer>
</div>
</div>
</section>
</div>
<script>
jQuery(function () {
SphinxRtdTheme.Navigation.enable(true);
});
</script>
</body>
</html>
|
