Index: dashboard.scm ================================================================== --- dashboard.scm +++ dashboard.scm @@ -159,11 +159,11 @@ ;; create a watch dog to move changes from lt/.db/*.db to megatest.db ;; ;;;(if (file-write-access? (conc *toppath* "/megatest.db")) ;;(debug:print-info 13 *default-log-port* "Before common:watchdog spawn") -(thread-start! (make-thread common:watchdog "Watchdog thread")) +;; (thread-start! (make-thread common:watchdog "Watchdog thread")) ;;(debug:print-info 13 *default-log-port* "After common:watchdog spawn") ;; (if (not (args:get-arg "-use-db-cache")) ;; (begin ;; (debug:print-info 0 *default-log-port* "Forcing db-cache mode due to read-only access to megatest.db") ;; (hash-table-set! args:arg-hash "-use-db-cache" #t)));;;) Index: db.scm ================================================================== --- db.scm +++ db.scm @@ -174,10 +174,21 @@ ;; ;; (stack-push! (dbr:dbstruct-dbstack dbstruct) newdb) ;; newdb) ;; (stack-pop! (dbr:subdb-dbstack subdb))) ;; (db:open-db subdb run-id))) ;; ) + +(define (db:get-db dbstruct run-id) + (let* ((subdb (dbfile:get-subdb dbstruct run-id)) + (dbdat (dbfile:get-dbdat dbstruct run-id))) + (if (dbr:dbdat? dbdat) + dbdat + (dbfile:open-db *dbstruct-dbs* #f db:initialize-main-db) + ) + ) +) + (define-inline (db:generic-error-printout exn . message) (print-call-chain (current-error-port)) (apply debug:print-error 0 *default-log-port* message) (debug:print-error 0 *default-log-port* " params: " params ", error: " ((condition-property-accessor 'exn 'message) exn) @@ -422,24 +433,30 @@ ;; sync run to disk if touched ;; (define (db:sync-touched dbstruct run-id #!key (force-sync #f)) (let* ((subdb (dbfile:get-subdb dbstruct run-id)) - (tmpdb (db:get-subdb dbstruct run-id)) - (mtdb (dbr:subdb-mtdb subdb)) - (refndb (dbr:subdb-refndb subdb)) + (tmpsubdb (dbfile:get-subdb dbstruct run-id)) + (tmpdbfile (dbr:subdb-tmpdbfile tmpsubdb)) + (mtdb (dbr:subdb-mtdbdat subdb)) + (tmpdb (dbfile:open-sqlite3-db tmpdbfile #f)) + + ;; (refndb (dbr:subdb-refndb subdb)) (start-t (current-seconds))) (debug:print-info 4 *default-log-port* "Syncing for run-id: " run-id) (mutex-lock! *db-multi-sync-mutex*) - (let ((update_info (cons (if force-sync 0 *db-last-sync*) "last_update"))) + (let ((update_info (cons "last_update" (if force-sync 0 *db-last-sync*) ))) (mutex-unlock! *db-multi-sync-mutex*) - (db:sync-tables (db:sync-all-tables-list dbstruct) update_info tmpdb refndb mtdb)) + (db:sync-tables (db:sync-all-tables-list dbstruct) update_info tmpdb mtdb)) (mutex-lock! *db-multi-sync-mutex*) (set! *db-last-sync* start-t) (set! *db-last-access* start-t) (mutex-unlock! *db-multi-sync-mutex*) - (stack-push! (dbr:subdb-dbstack subdb) tmpdb))) + (stack-push! (dbr:subdb-dbstack subdb) tmpdb)) + #t +) + ;; db:safely-close-sqlite3-db and db:close-all were here, moved to dbfile ;; (let ((locdbs (dbr:dbstruct-locdbs dbstruct))) ;; (if (hash-table? locdbs) @@ -656,22 +673,23 @@ (debug:print-error 0 *default-log-port* "Failed to rebuild " dbpath ", exiting now.") (exit))))) (cons todb slave-dbs)) 0) - ;; this is the work to be done + + ;; this is the work to be done") (cond ((not fromdb) (debug:print 3 *default-log-port* "WARNING: db:sync-tables called with fromdb missing") -1) ((not todb) (debug:print 3 *default-log-port* "WARNING: db:sync-tables called with todb missing") -2) ((not (sqlite3:database? (dbr:dbdat-dbh fromdb))) (debug:print-error 0 *default-log-port* "db:sync-tables called with fromdb not a database " fromdb) - -3) + -3) ((not (sqlite3:database? (dbr:dbdat-dbh todb))) (debug:print-error 0 *default-log-port* "db:sync-tables called with todb not a database " todb) - -4) + -4) ((not (file-write-access? (dbr:dbdat-dbfile todb))) (debug:print-error 0 *default-log-port* "db:sync-tables called with todb not a read-only database " todb) -5) ((not (null? (let ((readonly-slave-dbs @@ -684,10 +702,12 @@ (debug:print-error 0 *default-log-port* "db:sync-tables called with todb not a read-only database " bad-dbdat)) readonly-slave-dbs) readonly-slave-dbs))) -6) (else + (debug:print 3 *default-log-port* "db:sync-tables: args are good") + (let ((stmts (make-hash-table)) ;; table-field => stmt (all-stmts '()) ;; ( ( stmt1 value1 ) ( stml2 value2 )) (numrecs (make-hash-table)) (start-time (current-milliseconds)) (tot-count 0)) @@ -703,11 +723,11 @@ ((number? last-update) #f) ;; if not matched first entry then ignore last-update for this table ((and (pair? last-update) (member (car last-update) ;; last-update field name (map car fields))) #t) - (last-update + ((and last-update (not (pair? last-update)) (not (number? last-update))) (debug:print 0 *default-log-port* "ERROR: parameter last-update for db:sync-tables must be a pair or a number, received: " last-update);; found in fields #f) (else #f))) (last-update-value (if use-last-update ;; no need to check for has-last-update - it is already accounted for @@ -745,30 +765,39 @@ (lambda (field) (hash-table-set! field->num field count) (set! count (+ count 1))) fields) + (debug:print 3 *default-log-port* "fromdat: " fromdat) + ;; read the source table + ;; store a list of all rows in the table in fromdat, up to batch-len. + ;; Then add fromdat to the fromdats list, clear fromdat and repeat. (sqlite3:for-each-row (lambda (a . b) (set! fromdat (cons (apply vector a b) fromdat)) (if (> (length fromdat) batch-len) (begin (set! fromdats (cons fromdat fromdats)) (set! fromdat '()) - (set! totrecords (+ totrecords 1))))) + (set! totrecords (+ totrecords 1))) + ) + ) (dbr:dbdat-dbh fromdb) full-sel) - + + ;; Count less than batch-len as a record + (if (> (length fromdat) 0) + (set! totrecords (+ totrecords 1))) + ;; tack on remaining records in fromdat (if (not (null? fromdat)) (set! fromdats (cons fromdat fromdats))) (if (common:low-noise-print 120 "sync-records") - (debug:print-info 4 *default-log-port* "found " totrecords " records to sync")) + (debug:print 4 *default-log-port* "found " totrecords " records to sync")) - ;; read the target table; BBHERE (sqlite3:for-each-row (lambda (a . b) (hash-table-set! todat a (apply vector a b))) (dbr:dbdat-dbh todb) full-sel) @@ -778,23 +807,26 @@ (thread-sleep! delay-handicap) (debug:print-info 0 *default-log-port* "synthetic sync delay of "delay-handicap" seconds completed") ) ;; first pass implementation, just insert all changed rows + (for-each (lambda (targdb) (let* ((db (dbr:dbdat-dbh targdb)) (drp-trigger (if (member "last_update" field-names) (db:drop-trigger db tablename) #f)) (is-trigger-dropped (if (member "last_update" field-names) (db:is-trigger-dropped db tablename) #f)) - (stmth (sqlite3:prepare db full-ins))) + (stmth (sqlite3:prepare db full-ins)) + (changed-rows 0)) ;; (db:delay-if-busy targdb) ;; NO WAITING (if (member "last_update" field-names) (debug:print-info 3 *default-log-port* "is-trigger-dropped: " is-trigger-dropped)) + (for-each (lambda (fromdat-lst) (sqlite3:with-transaction db (lambda () @@ -811,17 +843,29 @@ (< i (- num-fields 1))) (loop (+ i 1)))) (if (not same) (begin (apply sqlite3:execute stmth (vector->list fromrow)) - (hash-table-set! numrecs tablename (+ 1 (hash-table-ref/default numrecs tablename 0))))))) + (hash-table-set! numrecs tablename (+ 1 (hash-table-ref/default numrecs tablename 0))) + (set! changed-rows (+ changed-rows 1)) + ) + ) + )) fromdat-lst)))) fromdats) + + + (debug:print 3 *default-log-port* "changed rows: " changed-rows) + + (sqlite3:finalize! stmth) (if (member "last_update" field-names) (db:create-trigger db tablename)))) - (append (list todb) slave-dbs)))) + (append (list todb) slave-dbs) + ) + ) + ) tbls) (let* ((runtime (- (current-milliseconds) start-time)) (should-print (or (debug:debug-mode 12) (common:low-noise-print 120 "db sync" (> runtime 500))))) ;; low and high sync times treated as separate. (if should-print (debug:print 3 *default-log-port* "INFO: db sync, total run time " runtime " ms")) @@ -1005,10 +1049,35 @@ ;; (conc cache-dir "/" fname) ;; use-last-update: #t))) ;; (thread-start! th1) ;; (apply proc cache-db params) ;; )))) + + + + +;; Get a lock from the no-sync-db for the from-db, then delta sync the from-db to the to-db, otherwise return #f + +(define (db:lock-and-delta-sync no-sync-db from-db-file to-db-file) + (assert (not *db-sync-in-progress*) "FATAL: db:lock-and-sync called while a sync is in progress.") + (let* ((lockdat (db:no-sync-get-lock no-sync-db from-db)) + (gotlock (car lockdat)) + (locktime (cdr lockdat))) + (if gotlock + (begin + (debug:print 0 *default-log-port* "db:lock-and-sync copying db") + ;; (file-copy from-db to-db #t) + (db:no-sync-del! no-sync-db from-db) + #t) + (begin + (debug:print 0 *default-log-port* "could not get lock for " from-db " from no-sync-db") + #f + )))) + + + + ;; options: ;; ;; 'killservers - kills all servers ;; 'dejunk - removes junk records @@ -1018,22 +1087,72 @@ ;; 'closeall - close all opened dbs ;; 'schema - attempt to apply schema changes ;; run-ids: '(1 2 3 ...) or #f (for all) ;; (define (db:multi-db-sync dbstruct . options) - ;; (if (not (launch:setup)) - ;; (debug:print 0 *default-log-port* "ERROR: not able to setup up for megatest.") - (assert #f "FATAL: Call to db:multi-db-sync which is not completed yet.") - (let* ((data-synced 0)) ;; count of changed records (I hope) + (db:open-db dbstruct #f) + + (let* ((data-synced 0) ;; count of changed records + (tmp-area (common:get-db-tmp-area)) + (dbfiles (glob (conc tmp-area"/.db/*.db"))) + (sync-durations (make-hash-table)) + ) + + (for-each + (lambda (file) + (debug:print-info 0 *default-log-port* "file: " file) + (let* ((fname (conc (pathname-file file) ".db")) + (fulln (conc *toppath*"/.db/"fname)) + (time1 (if (file-exists? file) + (file-modification-time file) + (begin + (debug:print-info 0 *default-log-port* "Sync - I do not see file "file) + 1))) + (time2 (if (file-exists? fulln) + (file-modification-time fulln) + (begin + (debug:print-info 0 *default-log-port* "Sync - I do not see file "fulln) + 0))) + (changed (> time1 time2)) + (do-cp (cond + ((not (file-exists? fulln)) ;; shouldn't happen, but this might recover + (debug:print-info 0 *default-log-port* "File "fulln" not found! Copying "fname" to "fulln) + #t) + (changed ;; (and changed + ;; (> (- (current-seconds) time1) 3)) ;; if file is changed and three seconds have passed. + #t) + ((and changed *time-to-exit*) ;; last sync + #t) + (else + #f)))) + (if do-cp + (let* ((start-time (current-milliseconds))) + (debug:print-info 0 *default-log-port* "delta sync delta file: " fname", delta: " (- time1 time2) " seconds") + (db:lock-and-delta-sync *no-sync-db* file fulln) + (hash-table-set! sync-durations (conc fname".db") (- (current-milliseconds) start-time))) + (debug:print-info 0 *default-log-port* "skipping delta sync. " file " is up to date") + ) + ) + ) + dbfiles + ) + + + (hash-table->alist sync-durations) + + + + (debug:print 0 *default-log-port* "db:multi-db-sync subdbs: " (hash-table-values (dbr:dbstruct-subdbs dbstruct))) (for-each (lambda (subdb) - (let* ((mtdb (dbr:subdb-mtdb subdb)) - (tmpdb (dbr:subdb-tmpdb subdb)) - (refndb (dbr:subdb-refndb subdb)) + (let* ((mtdb (dbr:subdb-mtdbdat subdb)) + (tmpdbfile (dbr:subdb-tmpdbfile subdb)) + (main-tmpdb (dbfile:open-db dbstruct #f db:initialize-main-db)) (allow-cleanup #t) ;; (if run-ids #f #t)) (servers (server:get-list *toppath*)) ;; (tasks:get-all-servers (db:delay-if-busy tdbdat))) ) + (debug:print 0 *default-log-port* "db:multi-db-sync mtdb: " mtdb " tmpdbfile:" tmpdbfile ) (for-each (lambda (option) (case option ;; kill servers @@ -1056,45 +1175,43 @@ ;; clear out junk records ;; ((dejunk) ;; (db:delay-if-busy mtdb) ;; ok to delay on mtdb (when (file-write-access? (dbr:dbdat-dbfile mtdb)) (db:clean-up mtdb)) - (db:clean-up tmpdb) - (db:clean-up refndb)) - - ;; sync runs, test_meta etc. + (db:clean-up main-tmpdb) + ) + ;; sync from main dbs to /tmp ones. ;; ((old2new) (set! data-synced - (+ (db:sync-tables (db:sync-all-tables-list dbstruct) #f mtdb tmpdb refndb) + (+ (db:sync-tables (db:sync-all-tables-list dbstruct) #f mtdb main-tmpdb) data-synced))) - ;; now ensure all newdb data are synced to megatest.db - ;; do not use the run-ids list passed in to the function + ;; sync from /tmp dbs to main ones. ;; ((new2old) (set! data-synced - (+ (db:sync-tables (db:sync-all-tables-list dbstruct) #f tmpdb refndb mtdb) + (+ (db:sync-tables (db:sync-all-tables-list dbstruct) #f main-tmpdb mtdb) data-synced))) ((adj-target) (db:adj-target (dbr:dbdat-dbh mtdb)) - (db:adj-target (dbr:dbdat-dbh tmpdb)) - (db:adj-target (dbr:dbdat-dbh refndb))) + (db:adj-target (dbr:dbdat-dbh main-tmpdb)) + ) ((schema) (db:patch-schema-maindb (dbr:dbdat-dbh mtdb)) - (db:patch-schema-maindb (dbr:dbdat-dbh tmpdb)) - (db:patch-schema-maindb (dbr:dbdat-dbh refndb)) + (db:patch-schema-maindb (dbr:dbdat-dbh main-tmpdb)) (db:patch-schema-rundb (dbr:dbdat-dbh mtdb)) - (db:patch-schema-rundb (dbr:dbdat-dbh tmpdb)) - (db:patch-schema-rundb (dbr:dbdat-dbh refndb)))) - - (stack-push! (dbr:subdb-dbstack subdb) tmpdb)) + (db:patch-schema-rundb (dbr:dbdat-dbh main-tmpdb)) + ) + ) + (stack-push! (dbr:subdb-dbstack subdb) main-tmpdb)) options))) (hash-table-values (dbr:dbstruct-subdbs dbstruct))) - data-synced)) + data-synced) +) ;; Sync all changed db's ;; (define (db:tmp->megatest.db-sync dbstruct run-id last-update) (let* ((subdbs (hash-table-values (dbr:dbstruct-subdbs dbstruct))) @@ -4970,25 +5087,67 @@ ((dbr:dbstruct-read-only dbstruct) (debug:print-info 13 *default-log-port* "loading read-only watchdog") (common:readonly-watchdog dbstruct)) (else (debug:print-info 13 *default-log-port* "loading writable-watchdog.") - (let* ((syncer (or (configf:lookup *configdat* "server" "sync-method") "copy-sync"))) ;; "delta-sync"))) ;; "brute-force-sync"))) + (let* ((syncer (or (configf:lookup *configdat* "server" "sync-method") "delta-sync"))) ;; "delta-sync"))) ;; "brute-force-sync"))) (cond ((equal? syncer "brute-force-sync") (server:writable-watchdog-bruteforce dbstruct)) ((equal? syncer "delta-sync") (server:writable-watchdog-deltasync dbstruct)) ((equal? syncer "copy-sync") (server:writable-watchdog-copysync dbstruct)) (else - (debug:print-error 0 *default-log-port* "Unknown server/sync-method specified ("syncer") - valid values are brute-force-sync and delta-sync.") + (debug:print-error 0 *default-log-port* "Unknown server/sync-method specified ("syncer") - valid values are copy-sync, brute-force-sync and delta-sync.") (exit 1))) ;;(debug:print 1 *default-log-port* "INFO: ["(common:human-time)"] Syncer started (method="syncer")") ))) (debug:print-info 13 *default-log-port* "watchdog done.")) (debug:print-info 13 *default-log-port* "no need for watchdog on non-homehost")))) + + +(define (db:do-sync) + (let* ((syncer (or (configf:lookup *configdat* "server" "sync-method") "delta-sync")) + (dbstruct (db:setup #t))) + + (debug:print 0 *default-log-port* "db:do-sync: sync-method: " syncer) + (cond + ((equal? syncer "brute-force-sync") + (db:run-lock-and-sync *no-sync-db*)) + ((equal? syncer "delta-sync") + (debug:print 0 *default-log-port* "db:do-sync: db:multi-db-sync" ) + (let* ( + (tmpdbpth (dbr:dbstruct-tmppath dbstruct)) + (lockfile (conc tmpdbpth ".lock")) + (locked (common:simple-file-lock lockfile)) + (res (if locked + (db:multi-db-sync + dbstruct + 'new2old) + #f))) + (if res + (begin + (common:simple-file-release-lock lockfile) + (print "db:do-sync: Synced " res " records to megatest.db") + ) + (print "db:do-sync: Skipping sync, there is a sync in progress.") + ) + ) + ) + ((equal? syncer "copy-sync") + (db:run-lock-and-sync *no-sync-db*)) + (else + (debug:print-error 0 *default-log-port* "Unknown server/sync-method specified ("syncer") - valid values are copy-sync, brute-force-sync and delta-sync.") + (exit 1) + ) + ) + ) +) + + + (define (server:writable-watchdog-bruteforce dbstruct) (thread-sleep! 1) ;; delay for startup #;(let* ((do-a-sync (server:get-bruteforce-syncer dbstruct)) (final-sync (server:get-bruteforce-syncer dbstruct fork-to-background: #t persist-until-sync: #t))) @@ -5002,12 +5161,15 @@ ;; time to exit, close the no-sync db here (final-sync) (if (common:low-noise-print 30) (debug:print-info 0 *default-log-port* "Exiting watchdog timer, *time-to-exit* = " *time-to-exit*" pid="(current-process-id) - ))))) + )))) + ) + +;; Get a lock from the no-sync-db for the from-db, then copy the from-db to the to-db, otherwise return #f (define (db:lock-and-sync no-sync-db from-db to-db) (assert (not *db-sync-in-progress*) "FATAL: db:lock-and-sync called while a sync is in progress.") (let* ((lockdat (db:no-sync-get-lock no-sync-db from-db)) (gotlock (car lockdat)) @@ -5015,11 +5177,14 @@ (if gotlock (begin (file-copy from-db to-db #t) (db:no-sync-del! no-sync-db from-db) #t) - #f))) + (begin + (debug:print 0 *default-log-port* "could not get lock for " from-db " from no-sync-db") + #f + )))) ;; sync for filesystem local db writes ;; (define (db:run-lock-and-sync no-sync-db) (let* ((tmp-area (common:get-db-tmp-area)) @@ -5052,11 +5217,11 @@ #t) (else #f)))) (if do-cp (let* ((start-time (current-milliseconds))) - (debug:print-info 0 *default-log-port* "sync file: "file", fname: "fname", time1: "time1", time2: "time2) + (debug:print-info 0 *default-log-port* "sync copy file: " fname", delta: " (- time1 time2) " seconds") (db:lock-and-sync no-sync-db file fulln) (hash-table-set! sync-durations (conc fname".db") (- (current-milliseconds) start-time))) #;(debug:print-info 0 *default-log-port* "skipping sync...")))) dbfiles) (hash-table->alist sync-durations))) @@ -5079,12 +5244,12 @@ (no-sync-db (db:open-no-sync-db)) (sync-duration 0) ;; run time of the sync in milliseconds (tmp-area (common:get-db-tmp-area))) ;; Sync moved to http-transport keep-running loop (set! *no-sync-db* no-sync-db) ;; make the no sync db available to api calls - (debug:print-info 2 *default-log-port* "Periodic copy-based sync thread started. sync is "legacy-sync", tmp-area is "tmp-area) - (debug:print-info 3 *default-log-port* "watchdog starting. legacy-sync is "legacy-sync" pid="(current-process-id));; " this-wd-num="this-wd-num) + (debug:print-info 2 *default-log-port* "Periodic copy-based sync thread started. syncer is copy-sync, tmp-area is " tmp-area) + (debug:print-info 3 *default-log-port* "watchdog starting. syncer is copy-sync pid="(current-process-id));; " this-wd-num="this-wd-num) (if (and legacy-sync (not *time-to-exit*)) (begin (debug:print-info 0 *default-log-port* "Server running, periodic copy-based sync started.") (let loop () @@ -5111,136 +5276,114 @@ *time-to-exit*" pid="(current-process-id) ))))))) (define (server:writable-watchdog-deltasync dbstruct) ;; This is awful complex and convoluted. Plan to redo? ;; for now ... skip it. -;; ==> -;; ==> (thread-sleep! 0.05) ;; delay for startup -;; ==> (let ((legacy-sync (common:run-sync?)) -;; ==> (sync-stale-seconds (configf:lookup-number *configdat* "server" "sync-stale-seconds" default: 300)) -;; ==> (debug-mode (debug:debug-mode 1)) -;; ==> (last-time (current-seconds)) -;; ==> (no-sync-db (db:open-no-sync-db)) -;; ==> (stmt-cache #f) ;; (dbr:dbstruct-stmt-cache dbstruct)) -;; ==> (sync-duration 0) ;; run time of the sync in milliseconds -;; ==> (subdbs (hash-table-values (dbr:dbstruct-subdbs dbstruct)))) -;; ==> (set! *no-sync-db* no-sync-db) ;; make the no sync db available to api calls -;; ==> (debug:print-info 2 *default-log-port* "Periodic sync thread started.") -;; ==> (debug:print-info 3 *default-log-port* "watchdog starting. legacy-sync is " legacy-sync" pid="(current-process-id) );; " this-wd-num="this-wd-num) -;; ==> -;; ==> (if (and legacy-sync (not *time-to-exit*)) -;; ==> (begin -;; ==> (debug:print-info 0 *default-log-port* "Server running, periodic sync started.") + + (thread-sleep! 0.05) ;; delay for startup + (let ((legacy-sync (common:run-sync?))) + (sync-stale-seconds (configf:lookup-number *configdat* "server" "sync-stale-seconds" default: 300)) + (debug-mode (debug:debug-mode 1)) + (last-time (current-seconds)) + (no-sync-db (db:open-no-sync-db)) + (stmt-cache #f) ;; (dbr:dbstruct-stmt-cache dbstruct)) + (sync-duration 0) ;; run time of the sync in milliseconds + (subdbs (hash-table-values (dbr:dbstruct-subdbs dbstruct)))) + (set! *no-sync-db* no-sync-db) ;; make the no sync db available to api calls + (debug:print-info 2 *default-log-port* "Periodic sync thread started.") + (debug:print-info 3 *default-log-port* "watchdog starting. legacy-sync is " legacy-sync" pid="(current-process-id) );; " this-wd-num="this-wd-num) + + (if (and legacy-sync (not *time-to-exit*)) + (begin + (debug:print-info 0 *default-log-port* "Server running, periodic sync started.") (let loop () -;; ==> ;; sync for filesystem local db writes -;; ==> ;; -;; ==> (mutex-lock! *db-multi-sync-mutex*) -;; ==> (let* ((start-file (conc tmp-area "/.start-sync")) -;; ==> (end-file (conc tmp-area "/.end-sync")) -;; ==> -;; ==> (need-sync (>= *db-last-access* *db-last-sync*)) ;; no sync since last write -;; ==> (sync-in-progress *db-sync-in-progress*) -;; ==> (min-intersync-delay (configf:lookup-number *configdat* "server" "minimum-intersync-delay" default: 5)) -;; ==> (should-sync (and (not *time-to-exit*) -;; ==> (> (- (current-seconds) *db-last-sync*) min-intersync-delay))) ;; sync every five seconds minimum, deprecated logic, can probably be removed -;; ==> (start-time (current-seconds)) -;; ==> (cpu-load-adj (alist-ref 'adj-proc-load (common:get-normalized-cpu-load #f))) -;; ==> (mt-mod-time (file-modification-time mtpath)) -;; ==> (last-sync-start (if (common:file-exists? start-file) -;; ==> (file-modification-time start-file) -;; ==> 0)) -;; ==> (last-sync-end (if (common:file-exists? end-file) -;; ==> (file-modification-time end-file) -;; ==> 10)) -;; ==> (sync-period (+ 3 (* cpu-load-adj 30))) ;; as adjusted load increases increase the sync period -;; ==> (recently-synced (and (< (- start-time mt-mod-time) sync-period) ;; not useful if sync didn't modify megatest.db! -;; ==> (< mt-mod-time last-sync-start))) -;; ==> (sync-done (<= last-sync-start last-sync-end)) -;; ==> (sync-stale (> start-time (+ last-sync-start sync-stale-seconds))) -;; ==> (will-sync (and (not *time-to-exit*) ;; do not start a sync if we are in the process of exiting -;; ==> (or need-sync should-sync) -;; ==> (or sync-done sync-stale) -;; ==> (not sync-in-progress) -;; ==> (not recently-synced)))) -;; ==> (debug:print-info 13 *default-log-port* "WD writable-watchdog top of loop. need-sync="need-sync" sync-in-progress=" sync-in-progress -;; ==> " should-sync="should-sync" start-time="start-time" mt-mod-time="mt-mod-time" recently-synced="recently-synced" will-sync="will-sync -;; ==> " sync-done=" sync-done " sync-period=" sync-period) -;; ==> (if (and (> sync-period 5) -;; ==> (common:low-noise-print 30 "sync-period")) -;; ==> (debug:print-info 0 *default-log-port* "Increased sync period due to long sync times, sync took: " sync-period " seconds.")) -;; ==> ;; (if recently-synced (debug:print-info 0 *default-log-port* "Skipping sync due to recently-synced flag=" recently-synced)) -;; ==> ;; (debug:print-info 0 *default-log-port* "need-sync: " need-sync " sync-in-progress: " sync-in-progress " should-sync: " should-sync " will-sync: " will-sync) -;; ==> (if will-sync (set! *db-sync-in-progress* #t)) -;; ==> (mutex-unlock! *db-multi-sync-mutex*) -;; ==> (if will-sync -;; ==> (let (;; (max-sync-duration (configf:lookup-number *configdat* "server" "max-sync-duration")) ;; KEEPING THIS AVAILABLE BUT SHOULD NOT USE, I'M PRETTY SURE IT DOES NOT WORK! -;; ==> (sync-start (current-milliseconds))) -;; ==> (with-output-to-file start-file (lambda ()(print (current-process-id)))) -;; ==> -;; ==> ;; put lock here -;; ==> -;; ==> ;; (if (or (not max-sync-duration) -;; ==> ;; (< sync-duration max-sync-duration)) ;; NOTE: db:sync-to-megatest.db keeps track of time of last sync and syncs incrementally -;; ==> -;; ==> ;; -;; ==> -;; ==> (for-each -;; ==> (lambda (subdb) -;; ==> (let* (;;(dbstruct (db:setup)) -;; ==> (mtdb (dbr:subdb-mtdb subdb)) -;; ==> (mtpath (db:dbdat-get-path mtdb)) -;; ==> (tmp-area (common:get-db-tmp-area)) -;; ==> (res (db:sync-to-megatest.db dbstruct no-sync-db: no-sync-db))) ;; did we sync any data? If so need to set the db touched flag to keep the server alive -;; ==> (set! sync-duration (- (current-milliseconds) sync-start)) -;; ==> (if (> res 0) ;; some records were transferred, keep the db alive -;; ==> (begin -;; ==> (mutex-lock! *heartbeat-mutex*) -;; ==> (set! *db-last-access* (current-seconds)) -;; ==> (mutex-unlock! *heartbeat-mutex*) -;; ==> (debug:print-info 0 *default-log-port* "sync called, " res " records transferred.")) -;; ==> (debug:print-info 2 *default-log-port* "sync called but zero records transferred"))) -;; ==> ) -;; ==> subdbs))) -;; ==> ;; ;; TODO: factor this next routine out into a function -;; ==> ;; (with-input-from-pipe ;; this should not block other threads but need to verify this -;; ==> ;; (conc "megatest -sync-to-megatest.db -m testsuite:" (common:get-area-name) ":" *toppath*) -;; ==> ;; (lambda () -;; ==> ;; (let loop ((inl (read-line)) -;; ==> ;; (res #f)) -;; ==> ;; (if (eof-object? inl) -;; ==> ;; (begin -;; ==> ;; (set! sync-duration (- (current-milliseconds) sync-start)) -;; ==> ;; (cond -;; ==> ;; ((not res) -;; ==> ;; (debug:print 0 *default-log-port* "ERROR: sync from /tmp db to megatest.db appears to have failed. Recommended that you stop your runs and run \"megatest -cleanup-db\"")) -;; ==> ;; ((> res 0) -;; ==> ;; (mutex-lock! *heartbeat-mutex*) -;; ==> ;; (set! *db-last-access* (current-seconds)) -;; ==> ;; (mutex-unlock! *heartbeat-mutex*)))) -;; ==> ;; (let ((num-synced (let ((matches (string-match "^Synced (\\d+).*$" inl))) -;; ==> ;; (if matches -;; ==> ;; (string->number (cadr matches)) -;; ==> ;; #f)))) -;; ==> ;; (loop (read-line) -;; ==> ;; (or num-synced res)))))))))) -;; ==> -;; ==> (if will-sync -;; ==> (begin -;; ==> (mutex-lock! *db-multi-sync-mutex*) -;; ==> (set! *db-sync-in-progress* #f) -;; ==> (set! *db-last-sync* start-time) -;; ==> (with-output-to-file end-file (lambda ()(print (current-process-id)))) -;; ==> -;; ==> ;; release lock here -;; ==> -;; ==> (mutex-unlock! *db-multi-sync-mutex*))) -;; ==> (if (and debug-mode -;; ==> (> (- start-time last-time) 60)) -;; ==> (begin -;; ==> (set! last-time start-time) -;; ==> (debug:print-info 4 *default-log-port* "timestamp -> " (seconds->time-string (current-seconds)) ", time since start -> " (seconds->hr-min-sec (- (current-seconds) *time-zero*)))))) -;; ==> + ;; sync for filesystem local db writes + ;; + (mutex-lock! *db-multi-sync-mutex*) + (let* ((start-file (conc tmp-area "/.start-sync")) + (end-file (conc tmp-area "/.end-sync")) + + (need-sync (>= *db-last-access* *db-last-sync*)) ;; no sync since last write + (sync-in-progress *db-sync-in-progress*) + (min-intersync-delay (configf:lookup-number *configdat* "server" "minimum-intersync-delay" default: 5)) + (should-sync (and (not *time-to-exit*) + (> (- (current-seconds) *db-last-sync*) min-intersync-delay))) ;; sync every five seconds minimum, deprecated logic, can probably be removed + (start-time (current-seconds)) + (cpu-load-adj (alist-ref 'adj-proc-load (common:get-normalized-cpu-load #f))) + (mt-mod-time (file-modification-time mtpath)) + (last-sync-start (if (common:file-exists? start-file) + (file-modification-time start-file) + 0)) + (last-sync-end (if (common:file-exists? end-file) + (file-modification-time end-file) + 10)) + (sync-period (+ 3 (* cpu-load-adj 30))) ;; as adjusted load increases increase the sync period + (recently-synced (and (< (- start-time mt-mod-time) sync-period) ;; not useful if sync didn't modify megatest.db! + (< mt-mod-time last-sync-start))) + (sync-done (<= last-sync-start last-sync-end)) + (sync-stale (> start-time (+ last-sync-start sync-stale-seconds))) + (will-sync (and (not *time-to-exit*) ;; do not start a sync if we are in the process of exiting + (or need-sync should-sync) + (or sync-done sync-stale) + (not sync-in-progress) + (not recently-synced)))) + (debug:print-info 13 *default-log-port* "WD writable-watchdog top of loop. need-sync="need-sync" sync-in-progress=" sync-in-progress + " should-sync="should-sync" start-time="start-time" mt-mod-time="mt-mod-time" recently-synced="recently-synced" will-sync="will-sync + " sync-done=" sync-done " sync-period=" sync-period) + (if (and (> sync-period 5) + (common:low-noise-print 30 "sync-period")) + (debug:print-info 0 *default-log-port* "Increased sync period due to long sync times, sync took: " sync-period " seconds.")) + ;; (if recently-synced (debug:print-info 0 *default-log-port* "Skipping sync due to recently-synced flag=" recently-synced)) + ;; (debug:print-info 0 *default-log-port* "need-sync: " need-sync " sync-in-progress: " sync-in-progress " should-sync: " should-sync " will-sync: " will-sync) + (if will-sync (set! *db-sync-in-progress* #t)) + (mutex-unlock! *db-multi-sync-mutex*) + (if will-sync + (let (;; (max-sync-duration (configf:lookup-number *configdat* "server" "max-sync-duration")) ;; KEEPING THIS AVAILABLE BUT SHOULD NOT USE, I'M PRETTY SURE IT DOES NOT WORK! + (sync-start (current-milliseconds))) + (with-output-to-file start-file (lambda ()(print (current-process-id)))) + + ;; put lock here + + ;; (if (or (not max-sync-duration) + ;; (< sync-duration max-sync-duration)) ;; NOTE: db:sync-to-megatest.db keeps track of time of last sync and syncs incrementally + + ;; + + (for-each + (lambda (subdb) + (let* (;;(dbstruct (db:setup)) + (mtdb (dbr:subdb-mtdb subdb)) + (mtpath (db:dbdat-get-path mtdb)) + (tmp-area (common:get-db-tmp-area)) + (res (db:sync-to-megatest.db dbstruct no-sync-db: no-sync-db))) ;; did we sync any data? If so need to set the db touched flag to keep the server alive + (set! sync-duration (- (current-milliseconds) sync-start)) + (if (> res 0) ;; some records were transferred, keep the db alive + (begin + (mutex-lock! *heartbeat-mutex*) + (set! *db-last-access* (current-seconds)) + (mutex-unlock! *heartbeat-mutex*) + (debug:print-info 0 *default-log-port* "sync called, " res " records transferred.")) + (debug:print-info 2 *default-log-port* "sync called but zero records transferred"))) + ) + subdbs))) + + (if will-sync + (begin + (mutex-lock! *db-multi-sync-mutex*) + (set! *db-sync-in-progress* #f) + (set! *db-last-sync* start-time) + (with-output-to-file end-file (lambda ()(print (current-process-id)))) + + ;; release lock here + + (mutex-unlock! *db-multi-sync-mutex*))) + (if (and debug-mode + (> (- start-time last-time) 60)) + (begin + (set! last-time start-time) + (debug:print-info 4 *default-log-port* "timestamp -> " (seconds->time-string (current-seconds)) ", time since start -> " (seconds->hr-min-sec (- (current-seconds) *time-zero*)))))) + ;; keep going unless time to exit ;; (if (not *time-to-exit*) (let delay-loop ((count 0)) ;;(debug:print-info 13 *default-log-port* "delay-loop top; count="count" pid="(current-process-id)" this-wd-num="this-wd-num" *time-to-exit*="*time-to-exit*) @@ -5250,14 +5393,15 @@ (begin (thread-sleep! 1) (delay-loop (+ count 1)))) (if (not *time-to-exit*) (loop)))) -;; ==> ;; time to exit, close the no-sync db here -;; ==> (db:no-sync-close-db no-sync-db stmt-cache) +;; ;; time to exit, close the no-sync db here +;; (db:no-sync-close-db no-sync-db stmt-cache) (if (common:low-noise-print 30) - (debug:print-info 0 *default-log-port* "Exiting watchdog timer, *time-to-exit* = " *time-to-exit*" pid="(current-process-id) )))) ;; ))) ;;" this-wd-num="this-wd-num))))))) + (debug:print-info 0 *default-log-port* "Exiting watchdog timer, *time-to-exit* = " *time-to-exit*" pid="(current-process-id) )))) +)) (define (std-exit-procedure) ;;(common:telemetry-log-close) (on-exit (lambda () 0)) Index: http-transport.scm ================================================================== --- http-transport.scm +++ http-transport.scm @@ -461,20 +461,29 @@ (let loop ((count 0) (server-state 'available) (bad-sync-count 0) (start-time (current-milliseconds))) + ;; Use this opportunity to sync the tmp db to megatest.db (if (not server-going) ;; *dbstruct-dbs* (begin (debug:print 0 *default-log-port* "SERVER: dbprep") (set! *dbstruct-dbs* (db:setup #t)) ;; run-id)) FIXME!!! (set! server-going #t) (debug:print 0 *default-log-port* "SERVER: running, megatest version: " (common:get-full-version)) ;; NOTE: the server is NOT yet marked as running in the log. We do that in the keep-running routine. - (thread-start! *watchdog*)) + + ;; (thread-start! *watchdog*) + ) (if *no-sync-db* - (db:run-lock-and-sync *no-sync-db*))) + (begin + (debug:print 0 *default-log-port* "keep-running calling db:do-sync at " (time->string (seconds->local-time) "%H:%M:%S")) + (db:do-sync) + ;; (db:run-lock-and-sync *no-sync-db*) + ) + ) + ) ;; when things go wrong we don't want to be doing the various queries too often ;; so we strive to run this stuff only every four seconds or so. (let* ((sync-time (- (current-milliseconds) start-time)) (rem-time (quotient (- 4000 sync-time) 1000))) Index: megatest.scm ================================================================== --- megatest.scm +++ megatest.scm @@ -507,19 +507,19 @@ ;; The watchdog is to keep an eye on things like db sync etc. ;; ;; TODO: for multiple areas, we will have multiple watchdogs; and multiple threads to manage -(define *watchdog* (make-thread - (lambda () - (handle-exceptions - exn - (begin - (print-call-chain) - (print " message: " ((condition-property-accessor 'exn 'message) exn) ", exn=" exn)) - (common:watchdog))) - "Watchdog thread")) +;;(define *watchdog* (make-thread +;; (lambda () +;; (handle-exceptions +;; exn +;; (begin +;; (print-call-chain) +;; (print " message: " ((condition-property-accessor 'exn 'message) exn) ", exn=" exn)) +;; (common:watchdog))) +;; "Watchdog thread")) ;;(if (not (args:get-arg "-server")) ;; (thread-start! *watchdog*)) ;; if starting a server; wait till we get to running state before kicking off watchdog (let* ((no-watchdog-args '("-list-runs" @@ -547,12 +547,14 @@ (loop (car tail) (cdr tail)))))) (no-watchdog-args-vals (filter (lambda (x) x) (map args:get-arg no-watchdog-args))) (start-watchdog (and (null? no-watchdog-args-vals) start-watchdog-specail-arg-val))) ;(print "no-watchdog-args="no-watchdog-args "no-watchdog-args-vals="no-watchdog-args-vals " start-watchdog-specail-arg-val:" start-watchdog-specail-arg-val " start-watchdog:" start-watchdog) - (if start-watchdog - (thread-start! *watchdog*))) +;; (if start-watchdog +;; (thread-start! *watchdog*)) + #t +) ;; bracket open-output-file with code to make leading directory if it does not exist and handle exceptions (define (open-logfile logpath-in) (condition-case @@ -2479,12 +2481,12 @@ ((server:get-bruteforce-syncer (db:setup #t) persist-until-sync: #t)) (set! *didsomething* #t)) (if (args:get-arg "-sync-to-megatest.db") (let* ((duh (launch:setup)) - (dbstruct (db:setup #f)) - (tmpdbpth (cdr (dbr:dbstruct-tmpdb dbstruct))) + (dbstruct (db:setup #t)) + (tmpdbpth (dbr:dbstruct-tmppath dbstruct)) (lockfile (conc tmpdbpth ".lock")) (locked (common:simple-file-lock lockfile)) (res (if locked (db:multi-db-sync dbstruct @@ -2550,14 +2552,14 @@ ;;(debug:print-info 13 *default-log-port* "thread-join! watchdog") ;; join the watchdog thread if it has been thread-start!ed (it may not have been started in the case of a server that never enters running state) ;; (symbols returned by thread-state: created ready running blocked suspended sleeping terminated dead) ;; TODO: for multiple areas, we will have multiple watchdogs; and multiple threads to manage -(if (thread? *watchdog*) - (case (thread-state *watchdog*) - ((ready running blocked sleeping terminated dead) - (thread-join! *watchdog*)))) +;;(if (thread? *watchdog*) +;; (case (thread-state *watchdog*) +;; ((ready running blocked sleeping terminated dead) +;; (thread-join! *watchdog*)))) (set! *time-to-exit* #t) (if (not (eq? *globalexitstatus* 0)) (if (or (args:get-arg "-run")(args:get-arg "-runtests")(args:get-arg "-runall")) Index: tests/simplerun/thebeginning.scm ================================================================== --- tests/simplerun/thebeginning.scm +++ tests/simplerun/thebeginning.scm @@ -13,47 +13,97 @@ ;; dbfile:get-subdb ) ;; *************** dbfile.scm tests **************** + + (debug:print 0 *default-log-port* " tmp area: " (common:get-db-tmp-area)) + (define tmpdir (common:get-db-tmp-area)) (test #f #t (dbr:dbstruct? (dbfile:setup #t *toppath* tmpdir))) (test #f #t (dbr:dbstruct? (db:setup #t))) (define dbstruct *dbstruct-dbs*) -(test #f #t (dbr:dbdat? (dbfile:open-db *dbstruct-dbs* #f db:initialize-main-db))) -(define maindbdat (dbfile:open-db *dbstruct-dbs* #f db:initialize-main-db)) -(dbfile:add-dbdat dbstruct #f maindbdat) -(test #f #t (dbr:subdb? (dbfile:get-subdb dbstruct #f))) -(test #f #t (dbr:dbdat? (dbfile:get-dbdat dbstruct #f))) -(test #f #f (dbr:dbdat? (dbfile:get-dbdat dbstruct #f))) ;; stack empty so should fail. - -(test #f #t (hash-table? (dbr:dbstruct-subdbs dbstruct))) -(test #f #t (stack? (dbr:subdb-dbstack (dbfile:get-subdb dbstruct #f)))) -(test #f '("SYSTEM" "RELEASE") (db:get-keys *dbstruct-dbs*)) - - -(test #f #t (dbr:dbdat? (dbfile:open-db dbstruct 1 db:initialize-main-db))) -(define rundbdat (dbfile:open-db dbstruct 1 db:initialize-main-db)) -(dbfile:add-dbdat dbstruct 1 rundbdat) -(test #f #t (dbr:subdb? (dbfile:get-subdb dbstruct 1))) -(test #f #t (dbr:dbdat? (dbfile:get-dbdat dbstruct 1))) - -(test #f #t (db:close-all dbstruct)) - -(test #f #t (db:safely-close-sqlite3-db (dbr:dbdat-dbh rundbdat) (dbr:dbdat-stmt-cache rundbdat))) -(test #f #t (db:safely-close-sqlite3-db (dbr:dbdat-dbh maindbdat) (dbr:dbdat-stmt-cache maindbdat))) - -(test #f #t (> (dbfile:lazy-sqlite-db-modification-time ".db/main.db") 0)) - -(test #f #t (common:simple-file-lock "./db.lock")) -(test #f "./db.lock" (common:simple-file-release-lock "./db.lock")) +(test #f #t (dbr:subdb? (dbfile:init-subdb dbstruct #f db:initialize-main-db))) ;; this opens the nfs main db + +;; (test #f #t (dbr:dbdat? (dbfile:open-db *dbstruct-dbs* #f db:initialize-main-db))) ;; this opens the tmp db. +;; (define maindbdat (dbfile:open-db *dbstruct-dbs* #f db:initialize-main-db)) ;; this opens the tmp db. +;; (dbfile:add-dbdat dbstruct #f maindbdat) + +;;(test #f #t (dbr:subdb? (dbfile:get-subdb dbstruct #f))) +;; (test #f #t (dbr:dbdat? (dbfile:get-dbdat dbstruct #f))) +;; (test #f #f (dbr:dbdat? (dbfile:get-dbdat dbstruct #f))) ;; stack empty so should fail. + +;; (test #f #t (hash-table? (dbr:dbstruct-subdbs dbstruct))) +;; (test #f #t (stack? (dbr:subdb-dbstack (dbfile:get-subdb dbstruct #f)))) +;; (test #f '("SYSTEM" "RELEASE") (db:get-keys *dbstruct-dbs*)) + + + (test #f #t (dbr:dbdat? (dbfile:open-db dbstruct 1 db:initialize-main-db))) + (test #f #t (dbr:dbdat? (dbfile:open-db dbstruct 2 db:initialize-main-db))) + (define rundbdat (dbfile:open-db dbstruct 1 db:initialize-main-db)) + (define rundbdat2 (dbfile:open-db dbstruct 1 db:initialize-main-db)) + (dbfile:add-dbdat dbstruct 1 rundbdat) + (dbfile:add-dbdat dbstruct 2 rundbdat2) +;; (test #f #t (dbr:subdb? (dbfile:get-subdb dbstruct 1))) +;; (test #f #t (dbr:dbdat? (dbfile:get-dbdat dbstruct 1))) +;; (test #f #t (dbr:subdb? (dbfile:get-subdb dbstruct 2))) +;; (test #f #t (dbr:dbdat? (dbfile:get-dbdat dbstruct 2))) + +;; (test #f #t (db:close-all dbstruct)) + + +;; (test #f #t (> (dbfile:lazy-sqlite-db-modification-time ".db/main.db") 0)) +;; (test #f #t (> (dbfile:lazy-sqlite-db-modification-time ".db/1.db") 0)) +;; (test #f #t (> (dbfile:lazy-sqlite-db-modification-time ".db/2.db") 0)) + +;; (test #f #t (common:simple-file-lock "./db.lock")) +;; (test #f "./db.lock" (common:simple-file-release-lock "./db.lock")) ;; *************** db.scm tests **************** -(define thisdbdat (db:open-db dbstruct #f)) -(test #f #t (dbr:dbdat? thisdbdat)) +;; (define thisdbdat (db:open-db dbstruct #f)) +;; (test #f #t (dbr:dbdat? thisdbdat)) + +;; (test #f #t (dbr:dbdat? (db:get-db dbstruct #f))) +;; (test #f #t (dbr:dbdat? (db:get-db dbstruct 1))) +;; (test #f #t (dbr:dbdat? (db:get-db dbstruct 2))) + +;; (dbfile:add-dbdat dbstruct #f maindbdat) +;; (define maindbdat (dbfile:get-dbdat dbstruct #f)) +;; (dbfile:add-dbdat dbstruct #f maindbdat) + +(define mtdbdat2 (dbr:subdb-mtdbdat (dbfile:get-subdb dbstruct #f))) + +(define areapath (dbr:dbstruct-areapath dbstruct)) +(define mtdbpath (dbfile:run-id->path areapath #f)) +(define init-proc db:initialize-main-db) + +(define mtdbdat (dbfile:open-sqlite3-db mtdbpath init-proc)) + +(define maindb-handle (dbr:dbdat-dbh mtdbdat)) +(define maindb-handle2 (dbr:dbdat-dbh mtdbdat2)) +(debug:print 0 *default-log-port* "maindb handle: " maindb-handle) +(debug:print 0 *default-log-port* "maindb handle2: " maindb-handle2) + +(sqlite3:execute maindb-handle "vacuum") +(sqlite3:execute maindb-handle2 "vacuum") + +(define full-sel (conc "SELECT * from runs")) + +(sqlite3:for-each-row + (lambda (a . b) + (debug:print 0 *default-log-port* "a: " a " b: " b) + ) + maindb-handle + full-sel) + +(test #f #t (db:sync-touched dbstruct #f)) +(test #f #t (db:sync-touched dbstruct 1)) +(test #f #t (db:sync-touched dbstruct 2)) -(test #f #t (dbr:dbdat? (db:get-db dbstruct #f))) -(test #f #t (dbr:dbdat? (db:get-db dbstruct 1))) +(test #f #t (db:safely-close-sqlite3-db (dbr:dbdat-dbh rundbdat) (dbr:dbdat-stmt-cache rundbdat))) +(test #f #t (db:safely-close-sqlite3-db (dbr:dbdat-dbh rundbdat2) (dbr:dbdat-stmt-cache rundbdat2))) +(test #f #t (db:safely-close-sqlite3-db (dbr:dbdat-dbh mtdbdat) (dbr:dbdat-stmt-cache mtdbdat))) +