;;======================================================================
;; Copyright 2017, Matthew Welland.
;;
;; This file is part of Megatest.
;;
;; Megatest is free software: you can redistribute it and/or modify
;; it under the terms of the GNU General Public License as published by
;; the Free Software Foundation, either version 3 of the License, or
;; (at your option) any later version.
;;
;; Megatest is distributed in the hope that it will be useful,
;; but WITHOUT ANY WARRANTY; without even the implied warranty of
;; MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
;; GNU General Public License for more details.
;;
;; You should have received a copy of the GNU General Public License
;; along with Megatest. If not, see <http://www.gnu.org/licenses/>.
;;======================================================================
(declare (unit ezstepsmod))
(declare (uses debugprint))
(declare (uses commonmod))
(declare (uses configfmod))
(declare (uses mtargs))
(declare (uses mtver))
(declare (uses csv-xml))
(declare (uses keysmod))
(declare (uses mtmod))
(declare (uses rmtmod))
(declare (uses testsmod))
(declare (uses dbmod))
(module ezstepsmod
*
(import scheme
(prefix sqlite3 sqlite3:)
chicken.base
chicken.condition
chicken.file
chicken.file.posix
chicken.format
chicken.io
chicken.pathname
chicken.port
chicken.pretty-print
chicken.process
chicken.process-context
chicken.process-context.posix
chicken.sort
chicken.string
chicken.time
chicken.time.posix
(prefix base64 base64:)
csv-xml
csv-abnf
directory-utils
matchable
regex
s11n
srfi-1
srfi-13
srfi-18
srfi-69
stack
typed-records
z3
(prefix mtargs args:)
commonmod
configfmod
debugprint
;; keysmod
mtmod
mtver
rmtmod
testsmod
dbmod
)
;; strftime('%m/%d/%Y %H:%M:%S','now','localtime')
;; (use srfi-1 posix regex srfi-69 directory-utils call-with-environment-variables posix-extras
;; z3 csv typed-records pathname-expand matchable)
;;
;; (declare (unit ezsteps))
;; (declare (uses db))
;; (declare (uses common))
;; (declare (uses items))
;; (declare (uses runconfig))
;; ;; (declare (uses sdb))
;; ;; (declare (uses filedb))
;;
;; (include "common_records.scm")
;; (include "key_records.scm")
(include "db_records.scm")
;; (include "run_records.scm")
;;
;;
;;(rmt:get-test-info-by-id run-id test-id) -> testdat
(define message-window #f)
;; TODO: deprecate me in favor of ezsteps.scm
;;
(define (launch:runstep ezstep run-id test-id exit-info m tal testconfig all-steps-dat)
(let* ((stepname (car ezstep)) ;; do stuff to run the step
(stepinfo (cadr ezstep))
;; (let ((info (cadr ezstep)))
;; (if (proc? info) "" info)))
;; (stepproc (let ((info (cadr ezstep)))
;; (if (proc? info) info #f)))
(stepparts (string-match (regexp "^(\\{([^\\}\\{]*)\\}\\s*|)(.*)$") stepinfo))
(stepparams (if (and (list? stepparts)
(> (length stepparts) 1))
(list-ref stepparts 2)
#f)) ;; for future use, {VAR=1,2,3}, run step for each
(paramparts (if (string? stepparams)
(map (lambda (x)(string-split x "=")) (string-split-fields "[^;]*=[^;]*" stepparams))
'()))
(subrun (alist-ref "subrun" paramparts equal?))
(stepcmd (if (and (list? stepparts)
(> (length stepparts) 2))
(list-ref stepparts 3)
(conc "# error, no command for step "stepname)))
(script "") ; "#!/bin/bash\n") ;; yep, we depend on bin/bash FIXME!!!\
(logpro-file (conc stepname ".logpro"))
(html-file (conc stepname ".html"))
(dat-file (conc stepname ".dat"))
(tconfig-logpro (configf:lookup testconfig "logpro" stepname))
(logpro-used (common:file-exists? logpro-file)))
(setenv "MT_STEP_NAME" stepname)
(hash-table-set! all-steps-dat stepname `((params . ,paramparts)))
(debug:print 0 *default-log-port* "stepparts: " stepparts ", stepparams: " stepparams
", paramparts: " paramparts ", subrun: " subrun ", stepcmd: " stepcmd)
(if (and tconfig-logpro
(not logpro-used)) ;; no logpro file found but have a defn in the testconfig
(begin
(with-output-to-file logpro-file
(lambda ()
(print ";; logpro file extracted from testconfig\n"
";;")
(print tconfig-logpro)))
(set! logpro-used #t)))
;; NB// can safely assume we are in test-area directory
(debug:print 4 *default-log-port* "ezsteps:\n stepname: " stepname " stepinfo: " stepinfo " stepparts: " stepparts
" stepparams: " stepparams " stepcmd: " stepcmd)
;; ;; first source the previous environment
;; (let ((prev-env (conc ".ezsteps/" prevstep (if (string-search (regexp "csh")
;; (get-environment-variable "SHELL")) ".csh" ".sh"))))
;; (if (and prevstep (common:file-exists? prev-env))
;; (set! script (conc script "source " prev-env))))
;; call the command using mt_ezstep
;; (set! script (conc "mt_ezstep " stepname " " (if prevstep prevstep "x") " " stepcmd))
(debug:print 4 *default-log-port* "script: " script)
(rmt:teststep-set-status! run-id test-id stepname "start" "-" #f #f)
;; now launch the actual process
(call-with-environment-variables
(list (cons "PATH" (conc (get-environment-variable "PATH") ":.")))
(lambda () ;; (process-run "/bin/bash" "-c" "exec ls -l /tmp/foobar > /tmp/delme-more.log 2>&1")
(let* ((cmd (conc stepcmd " > " stepname ".log 2>&1")) ;; >outfile 2>&1
(pid #f))
(let ((proc (lambda ()
(set! pid (process-run "/bin/bash" (list "-c" cmd))))))
(if subrun
(begin
(debug:print-info 0 *default-log-port* "Running without MT_.* environment variables.")
(common:without-vars proc "^MT_.*"))
(proc)))
(with-output-to-file "Makefile.ezsteps"
(lambda ()
(print stepname ".log :")
(print "\t" cmd)
(if (common:file-exists? (conc stepname ".logpro"))
(print "\tlogpro " stepname ".logpro " stepname ".html < " stepname ".log"))
(print)
(print stepname " : " stepname ".log")
(print))
#:append)
(rmt:test-set-top-process-pid run-id test-id pid)
(let processloop ((i 0))
(let-values (((pid-val exit-status exit-code)(process-wait pid #t)))
(mutex-lock! m)
(launch:einf-pid-set! exit-info pid) ;; (vector-set! exit-info 0 pid)
(launch:einf-exit-status-set! exit-info exit-status) ;; (vector-set! exit-info 1 exit-status)
(launch:einf-exit-code-set! exit-info exit-code) ;; (vector-set! exit-info 2 exit-code)
(mutex-unlock! m)
(if (eq? pid-val 0)
(begin
(thread-sleep! 2)
(processloop (+ i 1))))
)))))
(debug:print-info 0 *default-log-port* "step " stepname " completed with exit code " (launch:einf-exit-code exit-info)) ;; (vector-ref exit-info 2))
;; now run logpro if needed
(if logpro-used
(let* ((logpro-exe (or (getenv "LOGPRO_EXE") "logpro"))
(pid (process-run (conc "/bin/sh -c '"logpro-exe" "logpro-file " " (conc stepname ".html") " < " stepname ".log > /dev/null'"))))
(let processloop ((i 0))
(let-values (((pid-val exit-status exit-code)(process-wait pid #t)))
(mutex-lock! m)
;; (make-launch:einf pid: pid exit-status: exit-status exit-code: exit-code)
(launch:einf-pid-set! exit-info pid) ;; (vector-set! exit-info 0 pid)
(launch:einf-exit-status-set! exit-info exit-status) ;; (vector-set! exit-info 1 exit-status)
(launch:einf-exit-code-set! exit-info exit-code) ;; (vector-set! exit-info 2 exit-code)
(mutex-unlock! m)
(if (eq? pid-val 0)
(begin
(thread-sleep! 2)
(processloop (+ i 1)))))
(debug:print-info 0 *default-log-port* "logpro for step " stepname " exited with code " (launch:einf-exit-code exit-info))))) ;; (vector-ref exit-info 2)))))
(let ((exinfo (launch:einf-exit-code exit-info)) ;; (vector-ref exit-info 2))
(logfna (if logpro-used (conc stepname ".html") ""))
(comment #f))
(if logpro-used
(let ((datfile (conc stepname ".dat")))
;; load the .dat file into the test_data table if it exists
(if (common:file-exists? datfile)
(set! comment (launch:load-logpro-dat run-id test-id stepname)))
(rmt:test-set-log! run-id test-id (conc stepname ".html"))))
(rmt:teststep-set-status! run-id test-id stepname "end" exinfo comment logfna))
;; set the test final status
(let* ((process-exit-status (launch:einf-exit-code exit-info)) ;; (vector-ref exit-info 2))
(this-step-status (cond
((and (eq? process-exit-status 2) logpro-used) 'warn) ;; logpro 2 = warnings
((and (eq? process-exit-status 3) logpro-used) 'check) ;; logpro 3 = check
((and (eq? process-exit-status 4) logpro-used) 'waived) ;; logpro 4 = waived
((and (eq? process-exit-status 5) logpro-used) 'abort) ;; logpro 5 = abort
((and (eq? process-exit-status 6) logpro-used) 'skip) ;; logpro 6 = skip
((eq? process-exit-status 0) 'pass) ;; logpro 0 = pass
(else 'fail)))
(overall-status (cond
((eq? (launch:einf-rollup-status exit-info) 2) 'warn) ;; rollup-status (vector-ref exit-info 3)
((eq? (launch:einf-rollup-status exit-info) 0) 'pass) ;; (vector-ref exit-info 3)
(else 'fail)))
(next-status (cond
((eq? overall-status 'pass) this-step-status)
((eq? overall-status 'warn)
(if (eq? this-step-status 'fail) 'fail 'warn))
((eq? overall-status 'abort) 'abort)
(else 'fail)))
(next-state ;; "RUNNING") ;; WHY WAS THIS CHANGED TO NOT USE (null? tal) ??
(cond
((null? tal) ;; more to run?
"COMPLETED")
(else "RUNNING"))))
(debug:print 4 *default-log-port* "Exit value received: " (launch:einf-exit-code exit-info) " logpro-used: " logpro-used
" this-step-status: " this-step-status " overall-status: " overall-status
" next-status: " next-status " rollup-status: " (launch:einf-rollup-status exit-info)) ;; (vector-ref exit-info 3))
(case next-status
((warn)
(launch:einf-rollup-status-set! exit-info 2) ;; (vector-set! exit-info 3 2) ;; rollup-status
;; NB// test-set-status! does rdb calls under the hood
(tests:test-set-status! run-id test-id next-state "WARN"
(if (eq? this-step-status 'warn) "Logpro warning found" #f)
#f))
((check)
(launch:einf-rollup-status-set! exit-info 3) ;; (vector-set! exit-info 3 3) ;; rollup-status
;; NB// test-set-status! does rdb calls under the hood
(tests:test-set-status! run-id test-id next-state "CHECK"
(if (eq? this-step-status 'check) "Logpro check found" #f)
#f))
((waived)
(launch:einf-rollup-status-set! exit-info 4) ;; (vector-set! exit-info 3 3) ;; rollup-status
;; NB// test-set-status! does rdb calls under the hood
(tests:test-set-status! run-id test-id next-state "WAIVED"
(if (eq? this-step-status 'check) "Logpro waived found" #f)
#f))
((abort)
(launch:einf-rollup-status-set! exit-info 5) ;; (vector-set! exit-info 3 4) ;; rollup-status
;; NB// test-set-status! does rdb calls under the hood
(tests:test-set-status! run-id test-id next-state "ABORT"
(if (eq? this-step-status 'abort) "Logpro abort found" #f)
#f))
((skip)
(launch:einf-rollup-status-set! exit-info 6) ;; (vector-set! exit-info 3 4) ;; rollup-status
;; NB// test-set-status! does rdb calls under the hood
(tests:test-set-status! run-id test-id next-state "SKIP"
(if (eq? this-step-status 'skip) "Logpro skip found" #f)
#f))
((pass)
(tests:test-set-status! run-id test-id next-state "PASS" #f #f))
(else ;; 'fail
(launch:einf-rollup-status-set! exit-info 1) ;; (vector-set! exit-info 3 1) ;; force fail, this used to be next-state but that doesn't make sense. should always be "COMPLETED"
(tests:test-set-status! run-id test-id "COMPLETED" "FAIL" (conc "Failed at step " stepname) #f)
)))
logpro-used))
(define (ezsteps:run-from testdat start-step-name run-one)
;;# TODO - recapture item variables, debug repeated step eval; regen logpro from test
(let* ((do-update-test-state-status #f)
(test-run-dir ;; (filedb:get-path *fdb*
(db:test-get-rundir testdat)) ;; )
(testconfig (read-config (conc test-run-dir "/testconfig") #f #t environ-patt: "pre-launch-env-vars"))
(ezstepslst (hash-table-ref/default testconfig "ezsteps" '()))
(run-mutex (make-mutex))
(rollup-status 0)
(rollup-status-string #f)
(rollup-status-sym #f)
(exit-info (vector #t #t #t))
(test-id (db:test-get-id testdat))
(run-id (db:test-get-run_id testdat))
(test-name (db:test-get-testname testdat))
(orig-test-state (db:test-get-state testdat))
(orig-test-status (db:test-get-status testdat))
(kill-job #f) ;; for future use (on re-factoring with launch.scm code
(the-step-params '())) ;; not exactly "functional"
;; keep trying till NFS deigns to populate test run dir on this host
(let loop ((count 5))
(if (not (common:file-exists? test-run-dir))
;;(push-directory test-run-dir)
(if (> count 0)
(begin
(debug:print 0 *default-log-port* "WARNING: ezsteps attempting to run but test run directory " test-run-dir " is not there. Waiting and trying again " count " more times")
(sleep 3)
(loop (- count 1))))))
(debug:print-info 0 *default-log-port* "Running in directory " test-run-dir)
(if (not (common:file-exists? ".ezsteps"))(create-directory ".ezsteps"))
;; if ezsteps was defined then we are sure to have at least one step but check anyway
(if (not (> (length ezstepslst) 0))
(if message-window
(message-window "ERROR: You can only re-run steps defined via ezsteps")
(debug:print 0 *default-log-port* "ERROR: You can only re-run steps defined via ezsteps"))
(begin
(let loop ((ezstep (car ezstepslst))
(tal (cdr ezstepslst))
(status-sym-so-far 'pass)
;;(runflag #f)
(saw-start-step-name #f)) ;; flag used to skip steps when not starting at the beginning
(if (or (vector-ref exit-info 1)
(equal? (alist-ref 'keep-going the-step-params) 'yes))
(let* ((prev-step-params the-step-params) ;; need to snag this now
(stepname (car ezstep)) ;; do stuff to run the step
(logpro-used (common:file-exists? (conc test-run-dir "/" stepname ".logpro")))
(stepinfo (cadr ezstep))
(stepparts (string-match (regexp "^(\\{([^\\}]*)\\}\\s*|)(.*)$") stepinfo))
(stepparms (list-ref stepparts 2)) ;; for future use, {VAR=1,2,3}, run step for each
(stepcmd (list-ref stepparts 3))
(script (conc "mt_ezstep '"test-run-dir"' '"stepname"' '"stepcmd"'")) ;; call the command using mt_ezstep
(saw-start-step-name-next (or saw-start-step-name (equal? stepname start-step-name)))
(proceed-with-this-step
(or (not start-step-name)
(equal? stepname start-step-name)
(and saw-start-step-name (not run-one))
saw-start-step-name-next
(and start-step-name (equal? stepname start-step-name))))
)
(debug:print 0 *default-log-port* "NOTE: stepparms=" stepparms)
(set! prev-step-params stepparms)
(set! do-update-test-state-status (and proceed-with-this-step (null? tal)))
;;(BB> "stepname="stepname" proceed-with-this-step="proceed-with-this-step " do-update-test-state-status="do-update-test-state-status " orig-test-state="orig-test-state" orig-test-status="orig-test-status)
(cond
((and (not proceed-with-this-step) (null? tal))
'done)
((not proceed-with-this-step)
(loop (car tal)
(cdr tal)
status-sym-so-far
saw-start-step-name-next))
(else
(debug:print 4 *default-log-port* "ezsteps:\n stepname: " stepname " stepinfo: " stepinfo " stepparts: " stepparts
" stepparms: " stepparms " stepcmd: " stepcmd)
(debug:print 4 *default-log-port* "script: " script)
(rmt:teststep-set-status! run-id test-id stepname "start" "-" #f #f)
;; now launch the script
(let ((pid (process-run script)))
(let processloop ((i 0))
(let-values (((pid-val exit-status exit-code)(process-wait pid #t)))
(mutex-lock! run-mutex)
(vector-set! exit-info 0 pid)
(vector-set! exit-info 1 exit-status)
(vector-set! exit-info 2 exit-code)
(mutex-unlock! run-mutex)
(if (eq? pid-val 0)
(begin
(thread-sleep! 1)
(processloop (+ i 1))))
))
(let ((exinfo (vector-ref exit-info 2))
(logfna (if logpro-used (conc stepname ".html") "")))
(rmt:teststep-set-status! run-id test-id stepname "end" exinfo #f logfna))
(if logpro-used
(rmt:test-set-log! run-id test-id (conc stepname ".html")))
;; set the test final status
(let* ((this-step-status (cond
(logpro-used
(common:logpro-exit-code->status-sym (vector-ref exit-info 2)))
((eq? (vector-ref exit-info 2) 0)
'pass)
(else
'fail)))
(overall-status-sym (common:worse-status-sym this-step-status status-sym-so-far))
(overall-status-string (status-sym->string overall-status-sym)))
(debug:print 4 *default-log-port* "Exit value received: " (vector-ref exit-info 2) " logpro-used: " logpro-used
" this-step-status: " this-step-status " overall-status: " overall-status-sym)
;;" next-status: " next-status " rollup-status: " rollup-status)
(set! rollup-status-string overall-status-string)
(set! rollup-status-sym overall-status-sym)
(tests:test-set-status! run-id test-id "RUNNING" overall-status-string #f #f)))
(if (and
(not run-one)
(common:steps-can-proceed-given-status-sym rollup-status-sym)
(not (null? tal)))
(loop (car tal)
(cdr tal)
rollup-status-sym
saw-start-step-name-next)))))
(debug:print 4 *default-log-port* "WARNING: a prior step failed, stopping at " ezstep)))
;; Once done with step/steps update the test record
;;
(let* ((item-path (db:test-get-item-path testdat)) ;; (item-list->path itemdat))
(testinfo (rmt:get-testinfo-state-status run-id test-id))) ;; refresh the testdat, call it iteminfo in case need prev/curr
;; Am I completed?
(if (equal? (db:test-get-state testinfo) "RUNNING") ;; (not (equal? (db:test-get-state testinfo) "COMPLETED"))
(let ((new-state (if kill-job "KILLED" "COMPLETED") ;; (if (eq? (vector-ref exit-info 2) 0) ;; exited with "good" status
;; "COMPLETED"
;; (db:test-get-state testinfo))) ;; else preseve the state as set within the test
)
(new-status rollup-status-string)
) ;; (db:test-get-status testinfo)))
(debug:print-info 2 *default-log-port* "Test NOT logged as COMPLETED, (state=" (db:test-get-state testinfo) "), updating result, rollup-status is " rollup-status)
(tests:test-set-status! run-id test-id
(if do-update-test-state-status new-state orig-test-state)
(if do-update-test-state-status new-status orig-test-status)
(args:get-arg "-m") #f)
;; need to update the top test record if PASS or FAIL and this is a subtest
(if (and (not (equal? item-path "")) do-update-test-state-status)
(rmt:set-state-status-and-roll-up-items run-id test-name item-path new-state new-status #f))))
;; for automated creation of the rollup html file this is a good place...
(if (not (equal? item-path ""))
(tests:summarize-items run-id test-id test-name #f)) ;; don't force - just update if no
)))
;;(pop-directory)
rollup-status-string))
(define (ezsteps:spawn-run-from testdat start-step-name run-one)
(thread-start!
(make-thread
(lambda ()
(ezsteps:run-from testdat start-step-name run-one))
(conc "ezstep run single step " start-step-name " run-one="run-one)))
)
;; return (conc status ": " comment) from the final section so that
;; the comment can be set in the step record in launch.scm
;;
(define (launch:load-logpro-dat run-id test-id stepname)
(let ((cname (conc stepname ".dat")))
(if (common:file-exists? cname)
(let* ((dat (read-config cname #f #f))
(csvr (db:logpro-dat->csv dat stepname))
(csvt (let-values (((fmt-cell fmt-record fmt-csv) (make-format ",")))
(fmt-csv (map list->csv-record csvr))))
(status (configf:lookup dat "final" "exit-status"))
(msg (configf:lookup dat "final" "message")))
(if csvt ;; this if blocked stack dump caused by .dat file from logpro being 0-byte. fixed by upgrading logpro
(rmt:csv->test-data run-id test-id csvt)
(debug:print 0 *default-log-port* "ERROR: no csvdat exists for run-id: " run-id " test-id: " test-id " stepname: " stepname ", check that logpro version is 1.15 or newer"))
;; (debug:print-info 13 *default-log-port* "Error: run-id/test-id/stepname="run-id"/"test-id"/"stepname" => bad csvr="csvr)
;; )
(cond
((equal? status "PASS") "PASS") ;; skip the message part if status is pass
(status (conc (configf:lookup dat "final" "exit-status") ": " (if msg msg "no message")))
(else #f)))
#f)))
)