File:  [ELWIX - Embedded LightWeight unIX -] / embedaddon / sqlite3 / test / walthread.test
Revision 1.1.1.1 (vendor branch): download - view: text, annotated - select for diffs - revision graph
Tue Feb 21 17:04:16 2012 UTC (12 years, 10 months ago) by misho
Branches: sqlite3, MAIN
CVS tags: v3_7_10, HEAD
sqlite3

    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>