walthread.test 15 KB

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