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