diff --git a/case-lib/apause.exp b/case-lib/apause.exp index 66fdec3d..e9abaaf7 100755 --- a/case-lib/apause.exp +++ b/case-lib/apause.exp @@ -81,7 +81,7 @@ proc rel_time_ms {} { proc press_space {} { global last_space_time - log 2 "Pressing SPACE" + log 1 "Pressing SPACE" send " " set last_space_time [rel_time_ms] log 3 "last_space_time set to $last_space_time" @@ -111,8 +111,8 @@ spawn {*}$argv set start_time_ms [clock milliseconds]; # re-adjust set last_space_time 0 ; # could not resist that name -# states: recording, pause_requested, paused, recording_requested -set state recording_requested +# states: active, pause_requested, paused, active_requested +set state active_requested set in_max_burst false set volume_always_zero true @@ -137,8 +137,20 @@ set volume_always_zero true expect { + # `man re_syntax` claims that Tcl regular expressions are compliant + # with the basic and extended POSIX ones while adding a 3rd, + # extended flavor. It's not clear which flavor `expect -re` uses + # but it's not the basic one. + # Use {} not "" to avoid quoting issues and backslash proliferation. + # When multiple patterns match, first pattern wins. + -nocase -re {error.*\r|PAUSE.*no[[:blank:]]*hw[[:blank:]]*support.*\r} { + set buffer_with_lf "[cr_to_lf $expect_out(buffer)]" + log 0 "ERROR: $buffer_with_lf" + exit 1 + } + # Volume xx% or MAX line # # When not backpressured by a sleeping (=bad!) Expect process, @@ -182,13 +194,13 @@ expect { switch $state { - recording { - log 2 "Recording volume #... | xx%:\n[cr_to_lf $expect_out(buffer)]" + active { + log 2 "Volume #... | __%:\n[cr_to_lf $expect_out(buffer)]" exp_continue } pause_requested { - log 2 "Volume #... | xx% left after requesting pause:\n[cr_to_lf $expect_out(buffer)]" + log 2 "Volume #... | __% left after requesting pause:\n[cr_to_lf $expect_out(buffer)]" exp_continue } @@ -198,12 +210,12 @@ expect { exit 1 } - recording_requested { - # First volume line printed since unpaused; recording successfully started! - set state recording + active_requested { + # First volume line printed since unpaused; stream successfully started! + set state active set _record_for [rand_min_range $rnd_min $rnd_range] - log 1 "($pauses_counter/$repeat_count) Found volume ### | xx%, recording for $_record_for ms" + log 1 "($pauses_counter/$repeat_count) Found volume ### | __%, active for $_record_for ms" set _delay [substract_time_since_last_space $_record_for] after $_delay "press_space; set state pause_requested" @@ -225,12 +237,8 @@ expect { {=== PAUSE ===} { if {$state != "pause_requested"} { - # TODO: upgrade this to an ERROR if we want to fix pause bugs like - # https://github.com/thesofproject/linux/issues/5109 - # As of July 2024, pause is rather being disabled: - # https://github.com/thesofproject/linux/pull/5041 - log 0 "WARNING: received == PAUSE == while in state $state! Ignoring." - exp_continue + log 0 "ERROR: received == PAUSE == while in state $state!" + exit 1 } set state paused @@ -241,7 +249,7 @@ expect { log 1 "($pauses_counter/$repeat_count) Found === PAUSE === , pausing for $_pausing_for ms" set _delay [substract_time_since_last_space $_pausing_for] - after $_delay "press_space; set state recording_requested" + after $_delay "press_space; set state active_requested" log 3 "last_space_time=$last_space_time; timer in $_delay"