xref: /sqlite-3.40.0/test/walthread.test (revision b8fff29c)
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 }
21ifcapable !wal             { finish_test ; return }
22
23set 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#
28unset -nocomplain seconds
29set seconds(walthread-1) 20
30set seconds(walthread-2) 20
31set seconds(walthread-3) 20
32set seconds(walthread-4) 20
33set 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#
43proc 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#
57proc 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#
76proc 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#
216proc 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#
247do_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(101 + $::E(pid)));
281        INSERT INTO t1 VALUES(randomblob(101 + $::E(pid)));
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#
330if {[atomic_batch_write test.db]==0} {
331  do_thread_test2 walthread-2 -seconds $seconds(walthread-2) -init {
332    execsql { CREATE TABLE t1(x INTEGER PRIMARY KEY, y UNIQUE) }
333  } -thread RB 2 {
334
335    db close
336    set nRun 0
337    set nDel 0
338    while {[tt_continue]} {
339      sqlite3 db test.db
340      db busy busyhandler
341      db eval { SELECT * FROM sqlite_master }
342      catch { db eval { PRAGMA journal_mode = DELETE } }
343      db eval {
344        BEGIN;
345        INSERT INTO t1 VALUES(NULL, randomblob(100+$E(pid)));
346      }
347      incr nRun 1
348      incr nDel [file exists test.db-journal]
349      if {[file exists test.db-journal] + [file exists test.db-wal] != 1} {
350        error "File-system looks bad..."
351      }
352      db eval COMMIT
353
354      integrity_check
355      db close
356    }
357    list $nRun $nDel
358    set {} "[expr $nRun-$nDel] w, $nDel r"
359
360  } -thread WAL 2 {
361    db close
362    set nRun 0
363    set nDel 0
364    while {[tt_continue]} {
365      sqlite3 db test.db
366      db busy busyhandler
367      db eval { SELECT * FROM sqlite_master }
368      catch { db eval { PRAGMA journal_mode = WAL } }
369      db eval {
370        BEGIN;
371        INSERT INTO t1 VALUES(NULL, randomblob(110+$E(pid)));
372      }
373      incr nRun 1
374      incr nDel [file exists test.db-journal]
375      if {[file exists test.db-journal] + [file exists test.db-wal] != 1} {
376        error "File-system looks bad..."
377      }
378      db eval COMMIT
379
380      integrity_check
381      db close
382    }
383    set {} "[expr $nRun-$nDel] w, $nDel r"
384  }
385}
386
387do_thread_test walthread-3 -seconds $seconds(walthread-3) -init {
388  execsql {
389    PRAGMA journal_mode = WAL;
390    CREATE TABLE t1(cnt PRIMARY KEY, sum1, sum2);
391    CREATE INDEX i1 ON t1(sum1);
392    CREATE INDEX i2 ON t1(sum2);
393    INSERT INTO t1 VALUES(0, 0, 0);
394  }
395} -thread t 10 {
396
397  set nextwrite $E(pid)
398
399  proc wal_hook {zDb nEntry} {
400    if {$nEntry>10} {
401      set rc [catch { db eval {PRAGMA wal_checkpoint} } msg]
402      if {$rc && $msg != "database is locked"} { error $msg }
403    }
404    return 0
405  }
406  db wal_hook wal_hook
407
408  while {[tt_continue]} {
409    set max 0
410    while { $max != ($nextwrite-1) && [tt_continue] } {
411      set max [db eval { SELECT max(cnt) FROM t1 }]
412    }
413
414    if {[tt_continue]} {
415      set sum1 [db eval { SELECT sum(cnt) FROM t1 }]
416      set sum2 [db eval { SELECT sum(sum1) FROM t1 }]
417      db eval { INSERT INTO t1 VALUES($nextwrite, $sum1, $sum2) }
418      incr nextwrite $E(nthread)
419      integrity_check
420    }
421  }
422
423  set {} ok
424} -check {
425  puts "  Final db contains [db eval {SELECT count(*) FROM t1}] rows"
426  puts "  Final integrity-check says: [db eval {PRAGMA integrity_check}]"
427
428  # Check that the contents of the database are Ok.
429  set c 0
430  set s1 0
431  set s2 0
432  db eval { SELECT cnt, sum1, sum2 FROM t1 ORDER BY cnt } {
433    if {$c != $cnt || $s1 != $sum1 || $s2 != $sum2} {
434      error "database content is invalid"
435    }
436    incr s2 $s1
437    incr s1 $c
438    incr c 1
439  }
440}
441
442do_thread_test2 walthread-4 -seconds $seconds(walthread-4) -init {
443  execsql {
444    PRAGMA journal_mode = WAL;
445    CREATE TABLE t1(a INTEGER PRIMARY KEY, b UNIQUE);
446  }
447} -thread r 1 {
448  # This connection only ever reads the database. Therefore the
449  # busy-handler is not required. Disable it to check that this is true.
450  #
451  # UPDATE: That is no longer entirely true - as we don't use a blocking
452  # lock to enter RECOVER state. Which means there is a small chance a
453  # reader can see an SQLITE_BUSY.
454  #
455  while {[tt_continue]} {
456    integrity_check
457  }
458  set {} ok
459} -thread w 1 {
460
461  proc wal_hook {zDb nEntry} {
462    if {$nEntry>15} {db eval {PRAGMA wal_checkpoint}}
463    return 0
464  }
465  db wal_hook wal_hook
466  set row 1
467  while {[tt_continue]} {
468    db eval { REPLACE INTO t1 VALUES($row, randomblob(300)) }
469    incr row
470    if {$row == 10} { set row 1 }
471  }
472
473  set {} ok
474}
475
476
477# This test case attempts to provoke a deadlock condition that existed in
478# the unix VFS at one point. The problem occurred only while recovering a
479# very large wal file (one that requires a wal-index larger than the
480# initial default allocation of 64KB).
481#
482do_thread_test walthread-5 -seconds $seconds(walthread-5) -init {
483
484  proc log_file_size {nFrame pgsz} {
485    expr {12 + ($pgsz+16)*$nFrame}
486  }
487
488  execsql {
489    PRAGMA page_size = 1024;
490    PRAGMA journal_mode = WAL;
491    CREATE TABLE t1(x);
492    BEGIN;
493      INSERT INTO t1 VALUES(randomblob(900));
494      INSERT INTO t1 SELECT randomblob(900) FROM t1;      /*     2 */
495      INSERT INTO t1 SELECT randomblob(900) FROM t1;      /*     4 */
496      INSERT INTO t1 SELECT randomblob(900) FROM t1;      /*     8 */
497      INSERT INTO t1 SELECT randomblob(900) FROM t1;      /*    16 */
498      INSERT INTO t1 SELECT randomblob(900) FROM t1;      /*    32 */
499      INSERT INTO t1 SELECT randomblob(900) FROM t1;      /*    64 */
500      INSERT INTO t1 SELECT randomblob(900) FROM t1;      /*   128 */
501      INSERT INTO t1 SELECT randomblob(900) FROM t1;      /*   256 */
502      INSERT INTO t1 SELECT randomblob(900) FROM t1;      /*   512 */
503      INSERT INTO t1 SELECT randomblob(900) FROM t1;      /*  1024 */
504      INSERT INTO t1 SELECT randomblob(900) FROM t1;      /*  2048 */
505      INSERT INTO t1 SELECT randomblob(900) FROM t1;      /*  4096 */
506      INSERT INTO t1 SELECT randomblob(900) FROM t1;      /*  8192 */
507      INSERT INTO t1 SELECT randomblob(900) FROM t1;      /* 16384 */
508      INSERT INTO t1 SELECT randomblob(900) FROM t1;      /* 32768 */
509      INSERT INTO t1 SELECT randomblob(900) FROM t1;      /* 65536 */
510    COMMIT;
511  }
512
513  forcecopy test.db-wal bak.db-wal
514  forcecopy test.db bak.db
515  db close
516
517  forcecopy bak.db-wal test.db-wal
518  forcecopy bak.db test.db
519
520  if {[file size test.db-wal] < [log_file_size [expr 64*1024] 1024]} {
521    error "Somehow failed to create a large log file"
522  }
523  puts "Database with large log file recovered. Now running clients..."
524} -thread T 5 {
525  db eval { SELECT count(*) FROM t1 }
526}
527unset -nocomplain seconds
528
529finish_test
530