1: # 2010 April 13
2: #
3: # The author disclaims copyright to this source code. In place of
4: # a legal notice, here is a blessing:
5: #
6: # May you do good and not evil.
7: # May you find forgiveness for yourself and forgive others.
8: # May you share freely, never taking more than you give.
9: #
10: #***********************************************************************
11: # This file implements regression tests for SQLite library. The
12: # focus of this file is testing the operation of the library in
13: # "PRAGMA journal_mode=WAL" mode with multiple threads.
14: #
15:
16: set testdir [file dirname $argv0]
17:
18: source $testdir/tester.tcl
19: source $testdir/lock_common.tcl
20: if {[run_thread_tests]==0} { finish_test ; return }
21: ifcapable !wal { finish_test ; return }
22:
23: set sqlite_walsummary_mmap_incr 64
24:
25: # How long, in seconds, to run each test for. If a test is set to run for
26: # 0 seconds, it is omitted entirely.
27: #
28: unset -nocomplain seconds
29: set seconds(walthread-1) 20
30: set seconds(walthread-2) 20
31: set seconds(walthread-3) 20
32: set seconds(walthread-4) 20
33: set seconds(walthread-5) 1
34:
35: # The parameter is the name of a variable in the callers context. The
36: # variable may or may not exist when this command is invoked.
37: #
38: # If the variable does exist, its value is returned. Otherwise, this
39: # command uses [vwait] to wait until it is set, then returns the value.
40: # In other words, this is a version of the [set VARNAME] command that
41: # blocks until a variable exists.
42: #
43: proc wait_for_var {varname} {
44: if {0==[uplevel [list info exists $varname]]} {
45: uplevel [list vwait $varname]
46: }
47: uplevel [list set $varname]
48: }
49:
50: # The argument is the name of a list variable in the callers context. The
51: # first element of the list is removed and returned. For example:
52: #
53: # set L {a b c}
54: # set x [lshift L]
55: # assert { $x == "a" && $L == "b c" }
56: #
57: proc lshift {lvar} {
58: upvar $lvar L
59: set ret [lindex $L 0]
60: set L [lrange $L 1 end]
61: return $ret
62: }
63:
64:
65: #-------------------------------------------------------------------------
66: # do_thread_test TESTNAME OPTIONS...
67: #
68: # where OPTIONS are:
69: #
70: # -seconds SECONDS How many seconds to run the test for
71: # -init SCRIPT Script to run before test.
72: # -thread NAME COUNT SCRIPT Scripts to run in threads (or processes).
73: # -processes BOOLEAN True to use processes instead of threads.
74: # -check SCRIPT Script to run after test.
75: #
76: proc do_thread_test {args} {
77:
78: set A $args
79:
80: set P(testname) [lshift A]
81: set P(seconds) 5
82: set P(init) ""
83: set P(threads) [list]
84: set P(processes) 0
85: set P(check) {
86: set ic [db eval "PRAGMA integrity_check"]
87: if {$ic != "ok"} { error $ic }
88: }
89:
90: unset -nocomplain ::done
91:
92: while {[llength $A]>0} {
93: set a [lshift A]
94: switch -glob -- $a {
95: -seconds {
96: set P(seconds) [lshift A]
97: }
98:
99: -init {
100: set P(init) [lshift A]
101: }
102:
103: -processes {
104: set P(processes) [lshift A]
105: }
106:
107: -check {
108: set P(check) [lshift A]
109: }
110:
111: -thread {
112: set name [lshift A]
113: set count [lshift A]
114: set prg [lshift A]
115: lappend P(threads) [list $name $count $prg]
116: }
117:
118: default {
119: error "Unknown option: $a"
120: }
121: }
122: }
123:
124: if {$P(seconds) == 0} {
125: puts "Skipping $P(testname)"
126: return
127: }
128:
129: puts "Running $P(testname) for $P(seconds) seconds..."
130:
131: catch { db close }
132: forcedelete test.db test.db-journal test.db-wal
133:
134: sqlite3 db test.db
135: eval $P(init)
136: catch { db close }
137:
138: foreach T $P(threads) {
139: set name [lindex $T 0]
140: set count [lindex $T 1]
141: set prg [lindex $T 2]
142:
143: for {set i 1} {$i <= $count} {incr i} {
144: set vars "
145: set E(pid) $i
146: set E(nthread) $count
147: set E(seconds) $P(seconds)
148: "
149: set program [string map [list %TEST% $prg %VARS% $vars] {
150:
151: %VARS%
152:
153: proc usleep {ms} {
154: set ::usleep 0
155: after $ms {set ::usleep 1}
156: vwait ::usleep
157: }
158:
159: proc integrity_check {{db db}} {
160: set ic [$db eval {PRAGMA integrity_check}]
161: if {$ic != "ok"} {error $ic}
162: }
163:
164: proc busyhandler {n} { usleep 10 ; return 0 }
165:
166: sqlite3 db test.db
167: db busy busyhandler
168: db eval { SELECT randomblob($E(pid)*5) }
169:
170: set ::finished 0
171: after [expr $E(seconds) * 1000] {set ::finished 1}
172: proc tt_continue {} { update ; expr ($::finished==0) }
173:
174: set rc [catch { %TEST% } msg]
175:
176: catch { db close }
177: list $rc $msg
178: }]
179:
180: if {$P(processes)==0} {
181: sqlthread spawn ::done($name,$i) $program
182: } else {
183: testfixture_nb ::done($name,$i) $program
184: }
185: }
186: }
187:
188: set report " Results:"
189: foreach T $P(threads) {
190: set name [lindex $T 0]
191: set count [lindex $T 1]
192: set prg [lindex $T 2]
193:
194: set reslist [list]
195: for {set i 1} {$i <= $count} {incr i} {
196: set res [wait_for_var ::done($name,$i)]
197: lappend reslist [lindex $res 1]
198: do_test $P(testname).$name.$i [list lindex $res 0] 0
199: }
200:
201: append report " $name $reslist"
202: }
203: puts $report
204:
205: sqlite3 db test.db
206: set res ""
207: if {[catch $P(check) msg]} { set res $msg }
208: do_test $P(testname).check [list set {} $res] ""
209: }
210:
211: # A wrapper around [do_thread_test] which runs the specified test twice.
212: # Once using processes, once using threads. This command takes the same
213: # arguments as [do_thread_test], except specifying the -processes switch
214: # is illegal.
215: #
216: proc do_thread_test2 {args} {
217: set name [lindex $args 0]
218: if {[lsearch $args -processes]>=0} { error "bad option: -processes"}
219: uplevel [lreplace $args 0 0 do_thread_test "$name-threads" -processes 0]
220: uplevel [lreplace $args 0 0 do_thread_test "$name-processes" -processes 1]
221: }
222:
223: #--------------------------------------------------------------------------
224: # Start 10 threads. Each thread performs both read and write
225: # transactions. Each read transaction consists of:
226: #
227: # 1) Reading the md5sum of all but the last table row,
228: # 2) Running integrity check.
229: # 3) Reading the value stored in the last table row,
230: # 4) Check that the values read in steps 1 and 3 are the same, and that
231: # the md5sum of all but the last table row has not changed.
232: #
233: # Each write transaction consists of:
234: #
235: # 1) Modifying the contents of t1 (inserting, updating, deleting rows).
236: # 2) Appending a new row to the table containing the md5sum() of all
237: # rows in the table.
238: #
239: # Each of the N threads runs N read transactions followed by a single write
240: # transaction in a loop as fast as possible.
241: #
242: # There is also a single checkpointer thread. It runs the following loop:
243: #
244: # 1) Execute "PRAGMA wal_checkpoint"
245: # 2) Sleep for 500 ms.
246: #
247: do_thread_test2 walthread-1 -seconds $seconds(walthread-1) -init {
248: execsql {
249: PRAGMA journal_mode = WAL;
250: CREATE TABLE t1(x PRIMARY KEY);
251: PRAGMA lock_status;
252: INSERT INTO t1 VALUES(randomblob(100));
253: INSERT INTO t1 VALUES(randomblob(100));
254: INSERT INTO t1 SELECT md5sum(x) FROM t1;
255: }
256: } -thread main 10 {
257:
258: proc read_transaction {} {
259: set results [db eval {
260: BEGIN;
261: PRAGMA integrity_check;
262: SELECT md5sum(x) FROM t1 WHERE rowid != (SELECT max(rowid) FROM t1);
263: SELECT x FROM t1 WHERE rowid = (SELECT max(rowid) FROM t1);
264: SELECT md5sum(x) FROM t1 WHERE rowid != (SELECT max(rowid) FROM t1);
265: COMMIT;
266: }]
267:
268: if {[llength $results]!=4
269: || [lindex $results 0] != "ok"
270: || [lindex $results 1] != [lindex $results 2]
271: || [lindex $results 2] != [lindex $results 3]
272: } {
273: error "Failed read transaction: $results"
274: }
275: }
276:
277: proc write_transaction {} {
278: db eval {
279: BEGIN;
280: INSERT INTO t1 VALUES(randomblob(100));
281: INSERT INTO t1 VALUES(randomblob(100));
282: INSERT INTO t1 SELECT md5sum(x) FROM t1;
283: COMMIT;
284: }
285: }
286:
287: # Turn off auto-checkpoint. Otherwise, an auto-checkpoint run by a
288: # writer may cause the dedicated checkpoint thread to return an
289: # SQLITE_BUSY error.
290: #
291: db eval { PRAGMA wal_autocheckpoint = 0 }
292:
293: set nRun 0
294: while {[tt_continue]} {
295: read_transaction
296: write_transaction
297: incr nRun
298: }
299: set nRun
300:
301: } -thread ckpt 1 {
302: set nRun 0
303: while {[tt_continue]} {
304: db eval "PRAGMA wal_checkpoint"
305: usleep 500
306: incr nRun
307: }
308: set nRun
309: }
310:
311: #--------------------------------------------------------------------------
312: # This test has clients run the following procedure as fast as possible
313: # in a loop:
314: #
315: # 1. Open a database handle.
316: # 2. Execute a read-only transaction on the db.
317: # 3. Do "PRAGMA journal_mode = XXX", where XXX is one of WAL or DELETE.
318: # Ignore any SQLITE_BUSY error.
319: # 4. Execute a write transaction to insert a row into the db.
320: # 5. Run "PRAGMA integrity_check"
321: #
322: # At present, there are 4 clients in total. 2 do "journal_mode = WAL", and
323: # two do "journal_mode = DELETE".
324: #
325: # Each client returns a string of the form "W w, R r", where W is the
326: # number of write-transactions performed using a WAL journal, and D is
327: # the number of write-transactions performed using a rollback journal.
328: # For example, "192 w, 185 r".
329: #
330: do_thread_test2 walthread-2 -seconds $seconds(walthread-2) -init {
331: execsql { CREATE TABLE t1(x INTEGER PRIMARY KEY, y UNIQUE) }
332: } -thread RB 2 {
333:
334: db close
335: set nRun 0
336: set nDel 0
337: while {[tt_continue]} {
338: sqlite3 db test.db
339: db busy busyhandler
340: db eval { SELECT * FROM sqlite_master }
341: catch { db eval { PRAGMA journal_mode = DELETE } }
342: db eval {
343: BEGIN;
344: INSERT INTO t1 VALUES(NULL, randomblob(100+$E(pid)));
345: }
346: incr nRun 1
347: incr nDel [file exists test.db-journal]
348: if {[file exists test.db-journal] + [file exists test.db-wal] != 1} {
349: error "File-system looks bad..."
350: }
351: db eval COMMIT
352:
353: integrity_check
354: db close
355: }
356: list $nRun $nDel
357: set {} "[expr $nRun-$nDel] w, $nDel r"
358:
359: } -thread WAL 2 {
360: db close
361: set nRun 0
362: set nDel 0
363: while {[tt_continue]} {
364: sqlite3 db test.db
365: db busy busyhandler
366: db eval { SELECT * FROM sqlite_master }
367: catch { db eval { PRAGMA journal_mode = WAL } }
368: db eval {
369: BEGIN;
370: INSERT INTO t1 VALUES(NULL, randomblob(110+$E(pid)));
371: }
372: incr nRun 1
373: incr nDel [file exists test.db-journal]
374: if {[file exists test.db-journal] + [file exists test.db-wal] != 1} {
375: error "File-system looks bad..."
376: }
377: db eval COMMIT
378:
379: integrity_check
380: db close
381: }
382: set {} "[expr $nRun-$nDel] w, $nDel r"
383: }
384:
385: do_thread_test walthread-3 -seconds $seconds(walthread-3) -init {
386: execsql {
387: PRAGMA journal_mode = WAL;
388: CREATE TABLE t1(cnt PRIMARY KEY, sum1, sum2);
389: CREATE INDEX i1 ON t1(sum1);
390: CREATE INDEX i2 ON t1(sum2);
391: INSERT INTO t1 VALUES(0, 0, 0);
392: }
393: } -thread t 10 {
394:
395: set nextwrite $E(pid)
396:
397: proc wal_hook {zDb nEntry} {
398: if {$nEntry>10} {
399: set rc [catch { db eval {PRAGMA wal_checkpoint} } msg]
400: if {$rc && $msg != "database is locked"} { error $msg }
401: }
402: return 0
403: }
404: db wal_hook wal_hook
405:
406: while {[tt_continue]} {
407: set max 0
408: while { $max != ($nextwrite-1) && [tt_continue] } {
409: set max [db eval { SELECT max(cnt) FROM t1 }]
410: }
411:
412: if {[tt_continue]} {
413: set sum1 [db eval { SELECT sum(cnt) FROM t1 }]
414: set sum2 [db eval { SELECT sum(sum1) FROM t1 }]
415: db eval { INSERT INTO t1 VALUES($nextwrite, $sum1, $sum2) }
416: incr nextwrite $E(nthread)
417: integrity_check
418: }
419: }
420:
421: set {} ok
422: } -check {
423: puts " Final db contains [db eval {SELECT count(*) FROM t1}] rows"
424: puts " Final integrity-check says: [db eval {PRAGMA integrity_check}]"
425:
426: # Check that the contents of the database are Ok.
427: set c 0
428: set s1 0
429: set s2 0
430: db eval { SELECT cnt, sum1, sum2 FROM t1 ORDER BY cnt } {
431: if {$c != $cnt || $s1 != $sum1 || $s2 != $sum2} {
432: error "database content is invalid"
433: }
434: incr s2 $s1
435: incr s1 $c
436: incr c 1
437: }
438: }
439:
440: do_thread_test2 walthread-4 -seconds $seconds(walthread-4) -init {
441: execsql {
442: PRAGMA journal_mode = WAL;
443: CREATE TABLE t1(a INTEGER PRIMARY KEY, b UNIQUE);
444: }
445: } -thread r 1 {
446: # This connection only ever reads the database. Therefore the
447: # busy-handler is not required. Disable it to check that this is true.
448: #
449: # UPDATE: That is no longer entirely true - as we don't use a blocking
450: # lock to enter RECOVER state. Which means there is a small chance a
451: # reader can see an SQLITE_BUSY.
452: #
453: while {[tt_continue]} {
454: integrity_check
455: }
456: set {} ok
457: } -thread w 1 {
458:
459: proc wal_hook {zDb nEntry} {
460: if {$nEntry>15} {db eval {PRAGMA wal_checkpoint}}
461: return 0
462: }
463: db wal_hook wal_hook
464: set row 1
465: while {[tt_continue]} {
466: db eval { REPLACE INTO t1 VALUES($row, randomblob(300)) }
467: incr row
468: if {$row == 10} { set row 1 }
469: }
470:
471: set {} ok
472: }
473:
474:
475: # This test case attempts to provoke a deadlock condition that existed in
476: # the unix VFS at one point. The problem occurred only while recovering a
477: # very large wal file (one that requires a wal-index larger than the
478: # initial default allocation of 64KB).
479: #
480: do_thread_test walthread-5 -seconds $seconds(walthread-5) -init {
481:
482: proc log_file_size {nFrame pgsz} {
483: expr {12 + ($pgsz+16)*$nFrame}
484: }
485:
486: execsql {
487: PRAGMA page_size = 1024;
488: PRAGMA journal_mode = WAL;
489: CREATE TABLE t1(x);
490: BEGIN;
491: INSERT INTO t1 VALUES(randomblob(900));
492: INSERT INTO t1 SELECT randomblob(900) FROM t1; /* 2 */
493: INSERT INTO t1 SELECT randomblob(900) FROM t1; /* 4 */
494: INSERT INTO t1 SELECT randomblob(900) FROM t1; /* 8 */
495: INSERT INTO t1 SELECT randomblob(900) FROM t1; /* 16 */
496: INSERT INTO t1 SELECT randomblob(900) FROM t1; /* 32 */
497: INSERT INTO t1 SELECT randomblob(900) FROM t1; /* 64 */
498: INSERT INTO t1 SELECT randomblob(900) FROM t1; /* 128 */
499: INSERT INTO t1 SELECT randomblob(900) FROM t1; /* 256 */
500: INSERT INTO t1 SELECT randomblob(900) FROM t1; /* 512 */
501: INSERT INTO t1 SELECT randomblob(900) FROM t1; /* 1024 */
502: INSERT INTO t1 SELECT randomblob(900) FROM t1; /* 2048 */
503: INSERT INTO t1 SELECT randomblob(900) FROM t1; /* 4096 */
504: INSERT INTO t1 SELECT randomblob(900) FROM t1; /* 8192 */
505: INSERT INTO t1 SELECT randomblob(900) FROM t1; /* 16384 */
506: INSERT INTO t1 SELECT randomblob(900) FROM t1; /* 32768 */
507: INSERT INTO t1 SELECT randomblob(900) FROM t1; /* 65536 */
508: COMMIT;
509: }
510:
511: forcecopy test.db-wal bak.db-wal
512: forcecopy test.db bak.db
513: db close
514:
515: forcecopy bak.db-wal test.db-wal
516: forcecopy bak.db test.db
517:
518: if {[file size test.db-wal] < [log_file_size [expr 64*1024] 1024]} {
519: error "Somehow failed to create a large log file"
520: }
521: puts "Database with large log file recovered. Now running clients..."
522: } -thread T 5 {
523: db eval { SELECT count(*) FROM t1 }
524: }
525: unset -nocomplain seconds
526:
527: finish_test
FreeBSD-CVSweb <freebsd-cvsweb@FreeBSD.org>