Home | History | Annotate | Download | only in test
      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   file delete -force 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   file copy -force test.db-wal bak.db-wal
    512   file copy -force test.db bak.db
    513   db close
    514 
    515   file copy -force bak.db-wal test.db-wal
    516   file copy -force 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
    528