Browse Source

Revamp event data model

Alois Mahdal 6 years ago
parent
commit
257bf1163f
4 changed files with 234 additions and 408 deletions
  1. 159
    165
      src/jat.sh.skel
  2. 25
    81
      tests/basic/oracle/ylog_both.stdout
  3. 25
    81
      tests/basic/oracle/ylog_fail.stdout
  4. 25
    81
      tests/basic/oracle/ylog_pass.stdout

+ 159
- 165
src/jat.sh.skel View File

138
     #     jat__cmd [-o R_OUT] [-e R_ERR] [-s R_ESF] [-S ES_EXPR] [--] CMD [ARG]..
138
     #     jat__cmd [-o R_OUT] [-e R_ERR] [-s R_ESF] [-S ES_EXPR] [--] CMD [ARG]..
139
     #
139
     #
140
     # Run CMD with all ARGs and if exit status is zero, announce assertion
140
     # Run CMD with all ARGs and if exit status is zero, announce assertion
141
-    # success (PASS), otherwise announce assertion failure (FAIL).
141
+    # success (ASSERT.PASS), otherwise announce assertion failure (ASSERT.FAIL).
142
     #
142
     #
143
     # Exit status expectation can be changed from zero to ES_EXPR, which
143
     # Exit status expectation can be changed from zero to ES_EXPR, which
144
     # must be in form of comma-separated list of integer values or ranges
144
     # must be in form of comma-separated list of integer values or ranges
164
     local __jat__hint
164
     local __jat__hint
165
     local __jat__beids=()
165
     local __jat__beids=()
166
     local __jat__caseid
166
     local __jat__caseid
167
-    local __jat__etype=TEST_ERROR
167
+    local __jat__etype=MESSAGE.ERROR
168
     local __jat__r_out
168
     local __jat__r_out
169
     local __jat__r_err
169
     local __jat__r_err
170
     local __jat__r_esf
170
     local __jat__r_esf
200
          || jat__log_error "error writing R_ESF file: $__jat__r_esf"
200
          || jat__log_error "error writing R_ESF file: $__jat__r_esf"
201
     fi
201
     fi
202
     if __jat__es_match "$__jat__o_es" "$__jat__r_es"; then
202
     if __jat__es_match "$__jat__o_es" "$__jat__r_es"; then
203
-        __jat__etype=PASS
203
+        __jat__etype=ASSERT.PASS
204
     else
204
     else
205
-        __jat__etype=FAIL
205
+        __jat__etype=ASSERT.FAIL
206
     fi
206
     fi
207
     __jat__assert $__jat__etype "$__jat__hint" "$__jat__caseid" "${__jat__beids[@]}" \
207
     __jat__assert $__jat__etype "$__jat__hint" "$__jat__caseid" "${__jat__beids[@]}" \
208
-        -- "t.cmd=${__jat__cmd[*]}" "o.es_expr=$__jat__o_es" "r.es=$__jat__r_es"
208
+        "t.cmd=${__jat__cmd[*]}" "o.es_expr=$__jat__o_es" "r.es=$__jat__r_es"
209
     return "$__jat__r_es"
209
     return "$__jat__r_es"
210
 }
210
 }
211
 
211
 
218
     #     jat__cmp [assert-options] RVAL OP OVAL
218
     #     jat__cmp [assert-options] RVAL OP OVAL
219
     #
219
     #
220
     # Compare RVAL (result value) to OVAL (oracle value) and announce
220
     # Compare RVAL (result value) to OVAL (oracle value) and announce
221
-    # assertion success (PASS) or assertion failure (FAIL).
221
+    # assertion success (ASSERT.PASS) or assertion failure (ASSERT.FAIL).
222
     #
222
     #
223
     # OP can be any of `eq`, `ne`, `lt`, `gt`, `le`, `ge` for numeric values,
223
     # OP can be any of `eq`, `ne`, `lt`, `gt`, `le`, `ge` for numeric values,
224
     # `==` and `re` for string values.  In case of `re`, OVAL is expected to
224
     # `==` and `re` for string values.  In case of `re`, OVAL is expected to
252
     __jat__cmp_match; cmpes=$?
252
     __jat__cmp_match; cmpes=$?
253
     case $cmpes in
253
     case $cmpes in
254
         0)
254
         0)
255
-            __jat__assert PASS "$hint" "$caseid" "${beids[@]}" \
256
-                -- "r.val=$RVal" "t.op=$Op" "o.val=$OVal"
255
+            __jat__assert ASSERT.PASS "$hint" "$caseid" "${beids[@]}" \
256
+                "r.val=$RVal" "t.op=$Op" "o.val=$OVal"
257
             ;;
257
             ;;
258
         1)
258
         1)
259
-            __jat__assert FAIL "$hint" "$caseid" "${beids[@]}" \
260
-                -- "r.val=$RVal" "t.op=$Op" "o.val=$OVal"
259
+            __jat__assert ASSERT.FAIL "$hint" "$caseid" "${beids[@]}" \
260
+                "r.val=$RVal" "t.op=$Op" "o.val=$OVal"
261
             ;;
261
             ;;
262
         *)
262
         *)
263
             __jat__usage "bad syntax: $RVal $Op $OVal"
263
             __jat__usage "bad syntax: $RVal $Op $OVal"
275
     #     jat__eval [assert-options] [-s R_ESF] [-S ES_EXPR] [--] CODE
275
     #     jat__eval [assert-options] [-s R_ESF] [-S ES_EXPR] [--] CODE
276
     #
276
     #
277
     # Run CODE using eval builtin and if exit status is zero, announce assertion
277
     # Run CODE using eval builtin and if exit status is zero, announce assertion
278
-    # success (PASS), otherwise announce assertion failure (FAIL).
278
+    # success (ASSERT.PASS), otherwise announce assertion failure (ASSERT.FAIL).
279
     #
279
     #
280
     # Exit status expectation can be changed from zero to ES_EXPR, which
280
     # Exit status expectation can be changed from zero to ES_EXPR, which
281
     # must be in form of comma-separated list of integer values or ranges
281
     # must be in form of comma-separated list of integer values or ranges
303
     local __jat__o_es=0
303
     local __jat__o_es=0
304
     local __jat__hint
304
     local __jat__hint
305
     local __jat__beids=()
305
     local __jat__beids=()
306
-    local __jat__etype=TEST_ERROR
306
+    local __jat__etype=MESSAGE.ERROR
307
     #
307
     #
308
     # NOTE: names need to be qualified because they might interfere
308
     # NOTE: names need to be qualified because they might interfere
309
     #       with the actual execution of the assert command.
309
     #       with the actual execution of the assert command.
334
     fi
334
     fi
335
     debug -v __jat__r_es
335
     debug -v __jat__r_es
336
     if __jat__es_match "$__jat__o_es" "$__jat__r_es"; then
336
     if __jat__es_match "$__jat__o_es" "$__jat__r_es"; then
337
-        __jat__etype=PASS
337
+        __jat__etype=ASSERT.PASS
338
     else
338
     else
339
-        __jat__etype=FAIL
339
+        __jat__etype=ASSERT.FAIL
340
     fi
340
     fi
341
     __jat__assert $__jat__etype "$__jat__hint" "$__jat__caseid" "${__jat__beids[@]}" \
341
     __jat__assert $__jat__etype "$__jat__hint" "$__jat__caseid" "${__jat__beids[@]}" \
342
-        -- "t.code=$__jat__code" "o.es_expr=$__jat__o_es" "r.es=$__jat__r_es"
342
+        "t.code=$__jat__code" "o.es_expr=$__jat__o_es" "r.es=$__jat__r_es"
343
     return "$__jat__r_es"
343
     return "$__jat__r_es"
344
 }
344
 }
345
 
345
 
359
     #
359
     #
360
     local hint      # log hint
360
     local hint      # log hint
361
     local caseid    # case ID
361
     local caseid    # case ID
362
-    local beids=()  # Behavior Evidence IDs
363
     while true; do case $1 in
362
     while true; do case $1 in
364
-        -b) beids+=("$2"); shift 2 || { __jat__usage "missing BEID"; return 2; } ;;
365
         -c) caseid="$2"; shift 2 || { __jat__usage "missing CASEID"; return 2; } ;;
363
         -c) caseid="$2"; shift 2 || { __jat__usage "missing CASEID"; return 2; } ;;
366
         -h) hint=$2; shift 2 || { __jat__usage "missing HINT"; return 2; } ;;
364
         -h) hint=$2; shift 2 || { __jat__usage "missing HINT"; return 2; } ;;
367
         *) break ;;
365
         *) break ;;
368
     esac done
366
     esac done
369
     test -n "$1" && { __jat__usage "extra arguments: $*"; return 2; }
367
     test -n "$1" && { __jat__usage "extra arguments: $*"; return 2; }
370
     debug -v hint beids
368
     debug -v hint beids
371
-    __jat__assert FAIL "$hint" "$caseid" "${beids[@]}"
369
+    __jat__assert ASSERT.FAIL "$hint" "$caseid" "${beids[@]}"
372
 }
370
 }
373
 
371
 
374
 jat__filebackup() {
372
 jat__filebackup() {
501
     }
499
     }
502
     es=$(__jat__final_es)
500
     es=$(__jat__final_es)
503
     __jat__show_sfinish
501
     __jat__show_sfinish
504
-    __jat__log_event SINFO "finishing session"
502
+    __jat__log_event SESSION.END "finishing session"
505
     __jat__writelog <<<"finalized: true"
503
     __jat__writelog <<<"finalized: true"
506
     __jat__writelog <<<"end: $(__jat__newstamp)"
504
     __jat__writelog <<<"end: $(__jat__newstamp)"
507
     fileas=$(__jat__sd_keyr fileas)
505
     fileas=$(__jat__sd_keyr fileas)
524
         $head || msg+=$'\n'; head=false
522
         $head || msg+=$'\n'; head=false
525
         msg+="$line"
523
         msg+="$line"
526
     done
524
     done
527
-    echo "error" >> "$(__jat__sd_path "llog")"
528
-    echo "error" >> "$(__jat__sd_path "P.llog")"
529
-    __jat__log_event TEST_ERROR "$msg"
525
+    echo "MESSAGE.ERROR" >> "$(__jat__sd_path "llog")"
526
+    echo "MESSAGE.ERROR" >> "$(__jat__sd_path "P.llog")"
527
+    __jat__log_event MESSAGE.ERROR "$msg"
530
 }
528
 }
531
 
529
 
532
 jat__log_info() {
530
 jat__log_info() {
541
         $head || msg+=$'\n'; head=false
539
         $head || msg+=$'\n'; head=false
542
         msg+="$line"
540
         msg+="$line"
543
     done
541
     done
544
-    echo "info" >> "$(__jat__sd_path "llog")"
545
-    echo "info" >> "$(__jat__sd_path "P.llog")"
546
-    __jat__log_event SINFO "$msg"
542
+    echo "MESSAGE.INFO" >> "$(__jat__sd_path "llog")"
543
+    echo "MESSAGE.INFO" >> "$(__jat__sd_path "P.llog")"
544
+    __jat__log_event MESSAGE.INFO "$msg"
547
 }
545
 }
548
 
546
 
549
 jat__log_warning() {
547
 jat__log_warning() {
558
         $head || msg+=$'\n'; head=false
556
         $head || msg+=$'\n'; head=false
559
         msg+="$line"
557
         msg+="$line"
560
     done
558
     done
561
-    echo "warning" >> "$(__jat__sd_path "llog")"
562
-    echo "warning" >> "$(__jat__sd_path "P.llog")"
563
-    __jat__log_event TEST_WARNING "$msg"
559
+    echo "MESSAGE.WARNING" >> "$(__jat__sd_path "llog")"
560
+    echo "MESSAGE.WARNING" >> "$(__jat__sd_path "P.llog")"
561
+    __jat__log_event MESSAGE.WARNING "$msg"
564
 }
562
 }
565
 
563
 
566
 jat__pass() {
564
 jat__pass() {
588
     esac done
586
     esac done
589
     test -n "$1" && { __jat__usage "extra arguments: $*"; return 2; }
587
     test -n "$1" && { __jat__usage "extra arguments: $*"; return 2; }
590
     debug -v hint beids
588
     debug -v hint beids
591
-    __jat__assert PASS "$hint" "$caseid" "${beids[@]}"
589
+    __jat__assert ASSERT.PASS "$hint" "$caseid" "${beids[@]}"
592
 }
590
 }
593
 
591
 
594
 jat__promise_asserts() {
592
 jat__promise_asserts() {
600
         __jat__usage "no NUM?"
598
         __jat__usage "no NUM?"
601
         return 2
599
         return 2
602
     }
600
     }
603
-    __jat__log_event PROMISE "assert number: $num" "" \
604
-        -- "num=$num"
601
+    __jat__log_event TEST.PROMISE "assert number: $num" "" \
602
+        "num=$num"
605
 }
603
 }
606
 
604
 
607
 jat__sinit() {
605
 jat__sinit() {
633
             warn -v JAT__TEST_VERSION old_test_version
631
             warn -v JAT__TEST_VERSION old_test_version
634
             die "cannot reload session of different test version"
632
             die "cannot reload session of different test version"
635
         }
633
         }
636
-        __jat__log_event SINFO "reloaded session" "" \
637
-            -- \
634
+        __jat__log_event SESSION.RELOAD "reloaded session" "" \
638
             "JAT__LOG_FMT=$__JAT__LOG_FMT" \
635
             "JAT__LOG_FMT=$__JAT__LOG_FMT" \
639
             "JAT__VERSION=$__JAT__SELF_VERSION"
636
             "JAT__VERSION=$__JAT__SELF_VERSION"
640
         __jat__show_sinitr
637
         __jat__show_sinitr
653
         __jat__sd_keyw test_id "$JAT__TEST_ID"
650
         __jat__sd_keyw test_id "$JAT__TEST_ID"
654
         __jat__sd_keyw test_version "$JAT__TEST_VERSION"
651
         __jat__sd_keyw test_version "$JAT__TEST_VERSION"
655
         __jat__pdummy
652
         __jat__pdummy
656
-        __jat__log_event SINFO "started new session"
653
+        __jat__log_event SESSION.START "started new session"
657
         __jat__show_sinitn
654
         __jat__show_sinitn
658
     fi
655
     fi
659
 }
656
 }
678
     #
675
     #
679
     local which=$1
676
     local which=$1
680
     case $which in
677
     case $which in
681
-        swarc)  grep -cxF warning "$(__jat__sd_path "llog")" ;;
682
-        pwarc)  grep -cxF warning "$(__jat__sd_path "P.llog")" ;;
683
-        serrc)  grep -cxF error "$(__jat__sd_path "llog")" ;;
684
-        perrc)  grep -cxF error "$(__jat__sd_path "P.llog")" ;;
685
-        sfailc) grep -cxF FAIL "$(__jat__sd_path "vlog")" ;;
686
-        pfailc) grep -cxF FAIL "$(__jat__sd_path "P.vlog")" ;;
687
-        ppassc) grep -cxF PASS "$(__jat__sd_path "P.vlog")" ;;
688
-        spassc) grep -cxF PASS "$(__jat__sd_path "vlog")" ;;
689
-        pasrtc) grep -cx 'PASS\|FAIL' "$(__jat__sd_path "P.vlog")" ;;
690
-        sasrtc) grep -cx 'PASS\|FAIL' "$(__jat__sd_path "vlog")" ;;
678
+        swarc)  grep -cxF MESSAGE.WARNING "$(__jat__sd_path "llog")" ;;
679
+        pwarc)  grep -cxF MESSAGE.WARNING "$(__jat__sd_path "P.llog")" ;;
680
+        serrc)  grep -cxF MESSAGE.ERROR "$(__jat__sd_path "llog")" ;;
681
+        perrc)  grep -cxF MESSAGE.ERROR "$(__jat__sd_path "P.llog")" ;;
682
+        sfailc) grep -cxF ASSERT.FAIL "$(__jat__sd_path "vlog")" ;;
683
+        pfailc) grep -cxF ASSERT.FAIL "$(__jat__sd_path "P.vlog")" ;;
684
+        ppassc) grep -cxF ASSERT.PASS "$(__jat__sd_path "P.vlog")" ;;
685
+        spassc) grep -cxF ASSERT.PASS "$(__jat__sd_path "vlog")" ;;
686
+        pasrtc) grep -cx 'ASSERT.PASS\|ASSERT.FAIL' "$(__jat__sd_path "P.vlog")" ;;
687
+        sasrtc) grep -cx 'ASSERT.PASS\|ASSERT.FAIL' "$(__jat__sd_path "vlog")" ;;
691
         *) __jat__usage "invalid statistic field: $which"
688
         *) __jat__usage "invalid statistic field: $which"
692
            return 2 ;;
689
            return 2 ;;
693
     esac
690
     esac
705
     }
702
     }
706
     __jat__show_pend
703
     __jat__show_pend
707
     __jat__pdummy
704
     __jat__pdummy
708
-    __jat__log_event SINFO
705
+    __jat__log_event PHASE.END
709
 }
706
 }
710
 
707
 
711
 jat__pstartd() {
708
 jat__pstartd() {
783
     # Use this function to create own asserts
780
     # Use this function to create own asserts
784
     #
781
     #
785
     case $1 in
782
     case $1 in
786
-        PASS)   __jat__show_pass "$2" ;;
787
-        FAIL)   __jat__show_fail "$2" ;;
783
+        ASSERT.PASS)   __jat__show_pass "$2" ;;
784
+        ASSERT.FAIL)   __jat__show_fail "$2" ;;
788
     esac
785
     esac
789
     __jat__log_event "$@"
786
     __jat__log_event "$@"
790
 }
787
 }
861
 
858
 
862
 __jat__log_event() {
859
 __jat__log_event() {
863
     #
860
     #
864
-    # Pass YAML log event to __jat__writelog()
861
+    # Log event to YAML log via __jat__writelog()
865
     #
862
     #
866
     # Usage:
863
     # Usage:
867
     #
864
     #
868
-    #     __jat__log_event ETYPE HINT CASEID [BEID].. -- [KEY=VALUE]..
869
-    #
870
-    # ETYPE can be FAIL, PASS, TEST_ERROR or SINFO (the latter two
871
-    # are for events unrelated to SUT, like internal errors or
872
-    # phase start/end events).
873
-    #
874
-    # HINT and BEIDs are explained in COMMON ARGUMENTS section of this
875
-    # manual.
876
-    #
877
-    # You can provide any amount of KEY=VALUE pairs, meaning of which
878
-    # is specific to every assert function.  (The assert function name
879
-    # is auto-detected and logged so that you can infer KEY meanings
880
-    # later.)  Each KEY must be simple word, except that prefixes of
881
-    # `t.`, `r.`, and `o.` are allowed to signify that the value logged
882
-    # is relevant to test method, result or oracle, respectively.
883
-    local etype=$1; shift
884
-    local hint=$1;    shift
885
-    local acaseid=$1; shift
886
-    local arg
865
+    #     __jat__log_event SESSION.START|SESSION.RELOAD|SESSION.END
866
+    #     __jat__log_event PHASE.END
867
+    #     __jat__log_event PHASE.START ID TYPE NAME [K=V]
868
+    #     __jat__log_event ASSERT.PASS|ASSERT.FAIL [-h HINT] [-c CASEID] [-b BEID..] [-d K=V..]
869
+    #     __jat__log_event MESSAGE.INFO|MESSAGE.WARNING|MESSAGE.ERROR MSG [K=V]
870
+    #
871
+    local EType=$1; shift
872
+    local msg
873
+    local meatfn
874
+    local caseid=$JAT__TEST_ID
887
     local beids=()
875
     local beids=()
888
-    local pairs=()
889
-    local real_beids=()
890
-    local caseid="$JAT__TEST_ID"
891
-    local pcaseid
892
-    local reading=beids
893
-    local pair
876
+    local data=()
894
     local origin=${FUNCNAME[1]}
877
     local origin=${FUNCNAME[1]}
878
+    local pcaseid
879
+    local CaseIdBase=$JAT__TEST_ID
895
     pcaseid=$(__jat__sd_keyR P.caseid)
880
     pcaseid=$(__jat__sd_keyR P.caseid)
896
-    test -n "$pcaseid" && caseid+=":$pcaseid"
897
-    test -n "$acaseid" && caseid+=":$acaseid"
898
-    case $etype in
899
-        PASS|FAIL|SINFO|TEST_ERROR|TEST_WARNING|PROMISE) : ;;
900
-        *)  __jat__show_error "bad ETYPE, changing to TEST_ERROR: $etype"
901
-            etype=TEST_ERROR ;;
881
+    test -n "$pcaseid" && CaseIdBase+=":$pcaseid"
882
+    case $EType in
883
+        ASSERT.PASS|ASSERT.FAIL) : ;;
884
+        MESSAGE.INFO|MESSAGE.ERROR|MESSAGE.WARNING) : ;;
885
+        PHASE.START|PHASE.END) : ;;
886
+        SESSION.START|SESSION.RELOAD|SESSION.END) : ;;
887
+        *)  __jat__usage "bad ETYPE: $EType"
888
+            return 2 ;;
902
     esac
889
     esac
903
-    case $etype:$origin in
904
-        PASS:__jat__assert)        : ;;
905
-        FAIL:__jat__assert)        : ;;
906
-        TEST_ERROR:__jat__usage)   : ;;
907
-        SINFO:jat__sinit)          : ;;
908
-        SINFO:jat__sfinish)        : ;;
909
-        SINFO:__jat__pstart)       : ;;
910
-        SINFO:jat__pend)           : ;;
911
-        SINFO:jat__log_info)       : ;;
912
-        TEST_ERROR:jat__log_error) : ;;
913
-        TEST_WARNING:jat__log_warning) : ;;
914
-        *)  __jat__show_error "illegal call of __jat__log_event: $etype from $origin"
915
-            etype=TEST_ERROR ;;
890
+    case $EType:$origin in
891
+        PHASE.END:jat__pend)                meatfn="true" ;;
892
+        PHASE.START:__jat__pstart)          meatfn="__jat__log_evt_pstart" ;;
893
+        SESSION.END:jat__sfinish)           meatfn="true" ;;
894
+        SESSION.RELOAD:jat__sinit)          meatfn="true" ;;
895
+        SESSION.START:jat__sinit)           meatfn="true" ;;
896
+        ASSERT.FAIL:__jat__assert)          meatfn="__jat__log_evt_assert" ;;
897
+        ASSERT.PASS:__jat__assert)          meatfn="__jat__log_evt_assert" ;;
898
+        MESSAGE.ERROR:__jat__usage)         meatfn="__jat__log_evt_message" ;;
899
+        MESSAGE.ERROR:jat__log_error)       meatfn="__jat__log_evt_message" ;;
900
+        MESSAGE.INFO:jat__log_info)         meatfn="__jat__log_evt_message" ;;
901
+        MESSAGE.WARNING:jat__log_warning)   meatfn="__jat__log_evt_message" ;;
902
+        *)  __jat__show_error "illegal call of __jat__log_event: $EType from $origin"
903
+            EType=MESSAGE.ERROR ;;
916
     esac
904
     esac
917
-    for arg in "$@"; do
918
-        case $reading:$arg in
919
-            *:)
920
-                shift
921
-                ;;
922
-            beids:--)
923
-                shift
924
-                reading=pairs
925
-                ;;
926
-            beids:*)
927
-                __jat__valid_beid "$arg" || {
928
-                    beids=(); pairs=(); etype=API_BUG
929
-                    hint="bad BEID syntax (must be simple id): '$arg'"
930
-                    __jat__show_error "$hint"
931
-                    break
932
-                }
933
-                beids+=("$arg")
934
-                shift
935
-                ;;
936
-            pairs:*)
937
-                __jat__valid_pair "$arg" || {
938
-                    beids=(); pairs=(); etype=API_BUG
939
-                    hint="bad K=V syntax: '$arg'"
940
-                    __jat__show_error "$hint"
941
-                    break
942
-                }
943
-                pairs+=("$arg")
944
-                shift
945
-                ;;
946
-        esac
947
-    done
948
-    for beid in "${beids[@]}"; do
949
-        case $beid in
950
-            "")     : ;;
951
-            *.*)    real_beids+=("$beid") ;;
952
-            *)      real_beids+=("$JAT__BEID_NS.$beid") ;;
953
-        esac
954
-    done
955
-    echo "$etype" >> "$(__jat__sd_path "vlog")"
956
-    echo "$etype" >> "$(__jat__sd_path "P.vlog")"
905
+    echo "$EType" >> "$(__jat__sd_path "vlog")"
906
+    echo "$EType" >> "$(__jat__sd_path "P.vlog")"
957
     {
907
     {
958
-        # NOTE: some scalars are printed directly for performance
959
-        #       reasons (these will never be null nor will they
960
-        #       contain YAML special chars)
961
-        #
962
-        echo "-"
963
-        echo "    origin: $origin"
964
-        echo "    etype: $etype"
965
-        echo "    stamp: $(__jat__newstamp)"
966
-        echo "    caseid: $caseid"
967
-        __jat__yamls hint "$hint"
968
-        __jat__yamla beids "${real_beids[@]}"
969
-        __jat__yamld data "${pairs[@]}"
970
-        echo "    phase:"
971
-        echo "        id: $(__jat__sd_keyr phase)"
972
-        echo "        name: $(__jat__sd_keyr P.name)"
973
-        echo "        type: $(__jat__sd_keyr P.type)"
974
-    } | sed 's/^/    /' | __jat__writelog
908
+        echo "    -"
909
+        echo "        etype: $EType"
910
+        echo "        stamp: $(__jat__newstamp)"
911
+        $meatfn "$@"
912
+    } | __jat__writelog
913
+}
914
+
915
+__jat__log_evt_pstart() {
916
+    #
917
+    #     __jat__log_event PHASE.START ID NAME TYPE [caseid=CASEID] [pdir=PDIR]
918
+    #
919
+    local pid=$1; shift
920
+    local pname=$1; shift
921
+    local ptype=$1; shift
922
+    local data=("$@")
923
+    echo "        phase:"
924
+    echo "            id: $pid"
925
+    echo "            type: $ptype"
926
+    echo "            name: |-4"
927
+    echo "                $pname"
928
+    __jat__yamld 2 data "${data[@]}"
929
+}
930
+
931
+__jat__log_evt_message() {
932
+    #     __jat__log_event MESSAGE.INFO|MESSAGE.WARNING|MESSAGE.ERROR MSG
933
+    local msg=$1; shift
934
+    local data=("$@")
935
+    __jat__yamls 2 message "$msg"
936
+    __jat__yamld 2 data "${data[@]}"
937
+}
938
+
939
+__jat__log_evt_assert() {
940
+    #     __jat__log_event ASSERT.PASS|ASSERT.FAIL HINT CASEID [K=V..]
941
+    local hint=$1; shift
942
+    local caseid=$1; shift
943
+    local data=("$@")
944
+    __jat__yamls 2 hint "$hint"
945
+    __jat__yamls 2 caseid "$caseid"
946
+    __jat__yamld 2 data "${data[@]}"
975
 }
947
 }
976
 
948
 
977
 __jat__newstamp() {
949
 __jat__newstamp() {
1003
     local pdir      # ^^ directory
975
     local pdir      # ^^ directory
1004
     local pcaseid   # ^^ case id, if assigned
976
     local pcaseid   # ^^ case id, if assigned
1005
     local oldphase  # current phase id
977
     local oldphase  # current phase id
978
+    local newphase  # new phase id
1006
     while true; do case $1 in
979
     while true; do case $1 in
1007
         -t) type="$2"; shift 2 || return 2 ;;
980
         -t) type="$2"; shift 2 || return 2 ;;
1008
         -c) pcaseid="$2"; shift 2 || return 2 ;;
981
         -c) pcaseid="$2"; shift 2 || return 2 ;;
1016
         jat__pend
989
         jat__pend
1017
     }
990
     }
1018
     debug -v type name pdir
991
     debug -v type name pdir
1019
-    __jat__sd_keyw phase "$(__jat__bumpid phasid)"
992
+    newphase=$(__jat__bumpid phasid)
993
+    __jat__sd_keyw phase "$newphase"
1020
     __jat__sd_keyw P.type "$type"
994
     __jat__sd_keyw P.type "$type"
1021
     __jat__sd_keyw P.name "$name"
995
     __jat__sd_keyw P.name "$name"
1022
     __jat__sd_keyw P.caseid "$pcaseid"
996
     __jat__sd_keyw P.caseid "$pcaseid"
1023
     __jat__show_pstart "$name"
997
     __jat__show_pstart "$name"
1024
-    __jat__log_event SINFO
998
+    __jat__log_event PHASE.START "$newphase" "$name" "$type" "caseid=$pcaseid" "pdir=$pdir"
1025
     test -n "$pdir" && {
999
     test -n "$pdir" && {
1026
         __jat__sd_keyw P.pdir "$pdir"
1000
         __jat__sd_keyw P.pdir "$pdir"
1027
         __jat__sd_keyw P.PWD "$PWD"
1001
         __jat__sd_keyw P.PWD "$PWD"
1259
     for patt in "${patts[@]}"; do
1233
     for patt in "${patts[@]}"; do
1260
         __jat__show_error "usage: $parent $patt"
1234
         __jat__show_error "usage: $parent $patt"
1261
     done
1235
     done
1262
-    __jat__log_event TEST_ERROR "bad usage: $parent()" "" \
1263
-        -- "PATTERNS=${patts[*]}"
1236
+    __jat__log_event MESSAGE.ERROR "bad usage: $parent()" "" \
1237
+        "PATTERNS=${patts[*]}"
1264
 }
1238
 }
1265
 
1239
 
1266
 __jat__writelog() {
1240
 __jat__writelog() {
1294
     #
1268
     #
1295
     # Print a scalar field named $1 with value $2
1269
     # Print a scalar field named $1 with value $2
1296
     #
1270
     #
1271
+    local nest=$1; shift
1297
     local name=$1
1272
     local name=$1
1298
     local value=$2
1273
     local value=$2
1274
+    local sp
1275
+    sp=$(__jat__yamlnest "$nest")
1299
     case $value in
1276
     case $value in
1300
-        "") echo "    $name: ~" ;;
1301
-        *)  echo "    $name: |-"
1302
-            sed "s/^/        /" <<<"$value" ;;
1277
+        "") echo "$sp$name: ~" ;;
1278
+        *)  echo "$sp$name: |-4"
1279
+            sed "s/^/$sp    /" <<<"$value" ;;
1303
     esac
1280
     esac
1304
 }
1281
 }
1305
 
1282
 
1307
     #
1284
     #
1308
     # Print an array field named $1 with array of values $2..
1285
     # Print an array field named $1 with array of values $2..
1309
     #
1286
     #
1287
+    local nest=$1; shift
1310
     local name=$1; shift
1288
     local name=$1; shift
1311
     local value
1289
     local value
1290
+    local sp
1291
+    sp=$(__jat__yamlnest "$nest")
1312
     test $# -eq 0 && echo "    $name: []" && return 0
1292
     test $# -eq 0 && echo "    $name: []" && return 0
1313
-    echo "    $name:"
1293
+    echo "$sp$name:"
1314
     for value in "$@"; do
1294
     for value in "$@"; do
1315
         case $value in
1295
         case $value in
1316
-            "") echo "        - ~" ;;
1317
-            *)  echo "        - |"
1318
-                echo "            $value" ;;
1296
+            "") echo "$sp    - ~" ;;
1297
+            *)  echo "$sp    - |-4"
1298
+                echo "$sp        $value" ;;
1319
         esac
1299
         esac
1320
     done
1300
     done
1321
 }
1301
 }
1322
 
1302
 
1303
+__jat__yamlnest() {
1304
+    #
1305
+    # Print $1 x 4 of spaces
1306
+    #
1307
+    local n=$1
1308
+    while test "$n" -gt 0; do
1309
+        echo -n '    '
1310
+        (( n-- ))
1311
+    done
1312
+}
1313
+
1323
 __jat__yamld() {
1314
 __jat__yamld() {
1324
     #
1315
     #
1325
     # Print a dict field named $1 and composed of KEY=VALUE pairs $2..
1316
     # Print a dict field named $1 and composed of KEY=VALUE pairs $2..
1326
     #
1317
     #
1318
+    local nest=$1; shift
1327
     local name=$1; shift
1319
     local name=$1; shift
1328
     local pair
1320
     local pair
1329
     local key
1321
     local key
1330
     local value
1322
     local value
1331
-    test $# -eq 0 && echo "    $name: {}" && return 0
1332
-    echo "    $name:"
1323
+    local sp
1324
+    sp=$(__jat__yamlnest "$nest")
1325
+    test $# -eq 0 && echo "$sp$name: {}" && return 0
1326
+    echo "$sp$name:"
1333
     for pair in "$@"; do
1327
     for pair in "$@"; do
1334
         key=${pair%%=*}; value=${pair#$key=}
1328
         key=${pair%%=*}; value=${pair#$key=}
1335
         case $value in
1329
         case $value in
1336
-            "") echo "        $key: ~" ;;
1337
-            *)  echo "        $key: |"
1338
-                echo "            $value" ;;
1330
+            "") echo "$sp    $key: ~" ;;
1331
+            *)  echo "$sp    $key: |-4"
1332
+                echo "$sp        $value" ;;
1339
         esac
1333
         esac
1340
     done
1334
     done
1341
 }
1335
 }

+ 25
- 81
tests/basic/oracle/ylog_both.stdout View File

7
 start: time-1
7
 start: time-1
8
 events:
8
 events:
9
     -
9
     -
10
-        origin: jat__sinit
11
-        etype: SINFO
10
+        etype: SESSION.START
12
         stamp: time-2
11
         stamp: time-2
13
-        caseid: _jat_anon_test_
14
-        hint: |-
15
-            started new session
16
-        beids: []
17
-        data: {}
18
-        phase:
19
-            id: dummy
20
-            name: _jat_dummy_phase_
21
-            type: none
22
     -
12
     -
23
-        origin: __jat__pstart
24
-        etype: SINFO
13
+        etype: PHASE.START
25
         stamp: time-3
14
         stamp: time-3
26
-        caseid: _jat_anon_test_
27
-        hint: ~
28
-        beids: []
29
-        data: {}
30
         phase:
15
         phase:
31
             id: phasid-1
16
             id: phasid-1
32
-            name: _jat_anon_phase_
33
             type: test
17
             type: test
18
+            name: |-4
19
+                _jat_anon_phase_
20
+        data:
21
+            caseid: ~
22
+            pdir: ~
34
     -
23
     -
35
-        origin: jat__log_info
36
-        etype: SINFO
24
+        etype: MESSAGE.INFO
37
         stamp: time-4
25
         stamp: time-4
38
-        caseid: _jat_anon_test_
39
-        hint: |-
26
+        message: |-4
40
             CMD: true
27
             CMD: true
41
-        beids: []
42
         data: {}
28
         data: {}
43
-        phase:
44
-            id: phasid-1
45
-            name: _jat_anon_phase_
46
-            type: test
47
     -
29
     -
48
-        origin: __jat__assert
49
-        etype: PASS
30
+        etype: ASSERT.PASS
50
         stamp: time-5
31
         stamp: time-5
51
-        caseid: _jat_anon_test_
52
-        hint: |-
32
+        hint: |-4
53
             true is true
33
             true is true
54
-        beids: []
34
+        caseid: ~
55
         data:
35
         data:
56
-            t.cmd: |
36
+            t.cmd: |-4
57
                 true
37
                 true
58
-            o.es_expr: |
38
+            o.es_expr: |-4
59
                 0
39
                 0
60
-            r.es: |
40
+            r.es: |-4
61
                 0
41
                 0
62
-        phase:
63
-            id: phasid-1
64
-            name: _jat_anon_phase_
65
-            type: test
66
     -
42
     -
67
-        origin: jat__log_info
68
-        etype: SINFO
43
+        etype: MESSAGE.INFO
69
         stamp: time-6
44
         stamp: time-6
70
-        caseid: _jat_anon_test_
71
-        hint: |-
45
+        message: |-4
72
             CMD: false
46
             CMD: false
73
-        beids: []
74
         data: {}
47
         data: {}
75
-        phase:
76
-            id: phasid-1
77
-            name: _jat_anon_phase_
78
-            type: test
79
     -
48
     -
80
-        origin: __jat__assert
81
-        etype: FAIL
49
+        etype: ASSERT.FAIL
82
         stamp: time-7
50
         stamp: time-7
83
-        caseid: _jat_anon_test_
84
-        hint: |-
51
+        hint: |-4
85
             false is true
52
             false is true
86
-        beids: []
53
+        caseid: ~
87
         data:
54
         data:
88
-            t.cmd: |
55
+            t.cmd: |-4
89
                 false
56
                 false
90
-            o.es_expr: |
57
+            o.es_expr: |-4
91
                 0
58
                 0
92
-            r.es: |
59
+            r.es: |-4
93
                 1
60
                 1
94
-        phase:
95
-            id: phasid-1
96
-            name: _jat_anon_phase_
97
-            type: test
98
     -
61
     -
99
-        origin: jat__pend
100
-        etype: SINFO
62
+        etype: PHASE.END
101
         stamp: time-8
63
         stamp: time-8
102
-        caseid: _jat_anon_test_
103
-        hint: ~
104
-        beids: []
105
-        data: {}
106
-        phase:
107
-            id: dummy
108
-            name: _jat_dummy_phase_
109
-            type: none
110
     -
64
     -
111
-        origin: jat__sfinish
112
-        etype: SINFO
65
+        etype: SESSION.END
113
         stamp: time-9
66
         stamp: time-9
114
-        caseid: _jat_anon_test_
115
-        hint: |-
116
-            finishing session
117
-        beids: []
118
-        data: {}
119
-        phase:
120
-            id: dummy
121
-            name: _jat_dummy_phase_
122
-            type: none
123
 finalized: true
67
 finalized: true
124
 end: time-10
68
 end: time-10

+ 25
- 81
tests/basic/oracle/ylog_fail.stdout View File

7
 start: time-1
7
 start: time-1
8
 events:
8
 events:
9
     -
9
     -
10
-        origin: jat__sinit
11
-        etype: SINFO
10
+        etype: SESSION.START
12
         stamp: time-2
11
         stamp: time-2
13
-        caseid: _jat_anon_test_
14
-        hint: |-
15
-            started new session
16
-        beids: []
17
-        data: {}
18
-        phase:
19
-            id: dummy
20
-            name: _jat_dummy_phase_
21
-            type: none
22
     -
12
     -
23
-        origin: __jat__pstart
24
-        etype: SINFO
13
+        etype: PHASE.START
25
         stamp: time-3
14
         stamp: time-3
26
-        caseid: _jat_anon_test_
27
-        hint: ~
28
-        beids: []
29
-        data: {}
30
         phase:
15
         phase:
31
             id: phasid-1
16
             id: phasid-1
32
-            name: _jat_anon_phase_
33
             type: test
17
             type: test
18
+            name: |-4
19
+                _jat_anon_phase_
20
+        data:
21
+            caseid: ~
22
+            pdir: ~
34
     -
23
     -
35
-        origin: jat__log_info
36
-        etype: SINFO
24
+        etype: MESSAGE.INFO
37
         stamp: time-4
25
         stamp: time-4
38
-        caseid: _jat_anon_test_
39
-        hint: |-
26
+        message: |-4
40
             CMD: true
27
             CMD: true
41
-        beids: []
42
         data: {}
28
         data: {}
43
-        phase:
44
-            id: phasid-1
45
-            name: _jat_anon_phase_
46
-            type: test
47
     -
29
     -
48
-        origin: __jat__assert
49
-        etype: FAIL
30
+        etype: ASSERT.FAIL
50
         stamp: time-5
31
         stamp: time-5
51
-        caseid: _jat_anon_test_
52
-        hint: |-
32
+        hint: |-4
53
             true is false
33
             true is false
54
-        beids: []
34
+        caseid: ~
55
         data:
35
         data:
56
-            t.cmd: |
36
+            t.cmd: |-4
57
                 true
37
                 true
58
-            o.es_expr: |
38
+            o.es_expr: |-4
59
                 1
39
                 1
60
-            r.es: |
40
+            r.es: |-4
61
                 0
41
                 0
62
-        phase:
63
-            id: phasid-1
64
-            name: _jat_anon_phase_
65
-            type: test
66
     -
42
     -
67
-        origin: jat__log_info
68
-        etype: SINFO
43
+        etype: MESSAGE.INFO
69
         stamp: time-6
44
         stamp: time-6
70
-        caseid: _jat_anon_test_
71
-        hint: |-
45
+        message: |-4
72
             CMD: false
46
             CMD: false
73
-        beids: []
74
         data: {}
47
         data: {}
75
-        phase:
76
-            id: phasid-1
77
-            name: _jat_anon_phase_
78
-            type: test
79
     -
48
     -
80
-        origin: __jat__assert
81
-        etype: FAIL
49
+        etype: ASSERT.FAIL
82
         stamp: time-7
50
         stamp: time-7
83
-        caseid: _jat_anon_test_
84
-        hint: |-
51
+        hint: |-4
85
             false is true
52
             false is true
86
-        beids: []
53
+        caseid: ~
87
         data:
54
         data:
88
-            t.cmd: |
55
+            t.cmd: |-4
89
                 false
56
                 false
90
-            o.es_expr: |
57
+            o.es_expr: |-4
91
                 0
58
                 0
92
-            r.es: |
59
+            r.es: |-4
93
                 1
60
                 1
94
-        phase:
95
-            id: phasid-1
96
-            name: _jat_anon_phase_
97
-            type: test
98
     -
61
     -
99
-        origin: jat__pend
100
-        etype: SINFO
62
+        etype: PHASE.END
101
         stamp: time-8
63
         stamp: time-8
102
-        caseid: _jat_anon_test_
103
-        hint: ~
104
-        beids: []
105
-        data: {}
106
-        phase:
107
-            id: dummy
108
-            name: _jat_dummy_phase_
109
-            type: none
110
     -
64
     -
111
-        origin: jat__sfinish
112
-        etype: SINFO
65
+        etype: SESSION.END
113
         stamp: time-9
66
         stamp: time-9
114
-        caseid: _jat_anon_test_
115
-        hint: |-
116
-            finishing session
117
-        beids: []
118
-        data: {}
119
-        phase:
120
-            id: dummy
121
-            name: _jat_dummy_phase_
122
-            type: none
123
 finalized: true
67
 finalized: true
124
 end: time-10
68
 end: time-10

+ 25
- 81
tests/basic/oracle/ylog_pass.stdout View File

7
 start: time-1
7
 start: time-1
8
 events:
8
 events:
9
     -
9
     -
10
-        origin: jat__sinit
11
-        etype: SINFO
10
+        etype: SESSION.START
12
         stamp: time-2
11
         stamp: time-2
13
-        caseid: _jat_anon_test_
14
-        hint: |-
15
-            started new session
16
-        beids: []
17
-        data: {}
18
-        phase:
19
-            id: dummy
20
-            name: _jat_dummy_phase_
21
-            type: none
22
     -
12
     -
23
-        origin: __jat__pstart
24
-        etype: SINFO
13
+        etype: PHASE.START
25
         stamp: time-3
14
         stamp: time-3
26
-        caseid: _jat_anon_test_
27
-        hint: ~
28
-        beids: []
29
-        data: {}
30
         phase:
15
         phase:
31
             id: phasid-1
16
             id: phasid-1
32
-            name: _jat_anon_phase_
33
             type: test
17
             type: test
18
+            name: |-4
19
+                _jat_anon_phase_
20
+        data:
21
+            caseid: ~
22
+            pdir: ~
34
     -
23
     -
35
-        origin: jat__log_info
36
-        etype: SINFO
24
+        etype: MESSAGE.INFO
37
         stamp: time-4
25
         stamp: time-4
38
-        caseid: _jat_anon_test_
39
-        hint: |-
26
+        message: |-4
40
             CMD: true
27
             CMD: true
41
-        beids: []
42
         data: {}
28
         data: {}
43
-        phase:
44
-            id: phasid-1
45
-            name: _jat_anon_phase_
46
-            type: test
47
     -
29
     -
48
-        origin: __jat__assert
49
-        etype: PASS
30
+        etype: ASSERT.PASS
50
         stamp: time-5
31
         stamp: time-5
51
-        caseid: _jat_anon_test_
52
-        hint: |-
32
+        hint: |-4
53
             true is true
33
             true is true
54
-        beids: []
34
+        caseid: ~
55
         data:
35
         data:
56
-            t.cmd: |
36
+            t.cmd: |-4
57
                 true
37
                 true
58
-            o.es_expr: |
38
+            o.es_expr: |-4
59
                 0
39
                 0
60
-            r.es: |
40
+            r.es: |-4
61
                 0
41
                 0
62
-        phase:
63
-            id: phasid-1
64
-            name: _jat_anon_phase_
65
-            type: test
66
     -
42
     -
67
-        origin: jat__log_info
68
-        etype: SINFO
43
+        etype: MESSAGE.INFO
69
         stamp: time-6
44
         stamp: time-6
70
-        caseid: _jat_anon_test_
71
-        hint: |-
45
+        message: |-4
72
             CMD: false
46
             CMD: false
73
-        beids: []
74
         data: {}
47
         data: {}
75
-        phase:
76
-            id: phasid-1
77
-            name: _jat_anon_phase_
78
-            type: test
79
     -
48
     -
80
-        origin: __jat__assert
81
-        etype: PASS
49
+        etype: ASSERT.PASS
82
         stamp: time-7
50
         stamp: time-7
83
-        caseid: _jat_anon_test_
84
-        hint: |-
51
+        hint: |-4
85
             false is false
52
             false is false
86
-        beids: []
53
+        caseid: ~
87
         data:
54
         data:
88
-            t.cmd: |
55
+            t.cmd: |-4
89
                 false
56
                 false
90
-            o.es_expr: |
57
+            o.es_expr: |-4
91
                 1
58
                 1
92
-            r.es: |
59
+            r.es: |-4
93
                 1
60
                 1
94
-        phase:
95
-            id: phasid-1
96
-            name: _jat_anon_phase_
97
-            type: test
98
     -
61
     -
99
-        origin: jat__pend
100
-        etype: SINFO
62
+        etype: PHASE.END
101
         stamp: time-8
63
         stamp: time-8
102
-        caseid: _jat_anon_test_
103
-        hint: ~
104
-        beids: []
105
-        data: {}
106
-        phase:
107
-            id: dummy
108
-            name: _jat_dummy_phase_
109
-            type: none
110
     -
64
     -
111
-        origin: jat__sfinish
112
-        etype: SINFO
65
+        etype: SESSION.END
113
         stamp: time-9
66
         stamp: time-9
114
-        caseid: _jat_anon_test_
115
-        hint: |-
116
-            finishing session
117
-        beids: []
118
-        data: {}
119
-        phase:
120
-            id: dummy
121
-            name: _jat_dummy_phase_
122
-            type: none
123
 finalized: true
67
 finalized: true
124
 end: time-10
68
 end: time-10