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