action #118663

open

[qe-core] wait_serial reports fail on serial_terminal when interactive cli is used

Added by ybonatakis over 1 year ago. Updated about 1 month ago.

Status:

New

Priority:

Normal

Assignee:

Category:

Enhancement to existing tests

Target version:

Start date:

2022-10-13

Due date:

% Done:

Estimated time:

Difficulty:

Description

Description¶

The problem appears in a scenario where you run a container and launch its interactive console and the module itself uses serial_terminal

autoinst-log.txt...autoinst-log.txt...

[2022-10-13T15:17:01.951831+02:00] [debug] tests/containers/apptainer.pm:50 called testapi::validate_script_output
[2022-10-13T15:17:01.952227+02:00] [debug] <<< testapi::wait_serial(timeout=90, buffer_size=undef, no_regex=1, expect_not_found=0, regexp="# ", quiet=1, record_output=undef)
[2022-10-13T15:17:01.953435+02:00] [debug] <<< consoles::serial_screen::read_until(timeout=90, no_regex=1, record_output=undef, buffer_size=undef, pattern=[
    "# "
  ], regexp="# ", expect_not_found=0, quiet=1, json_cmd_token="stLkEWrr", cmd="backend_wait_serial")
[2022-10-13T15:18:32.041417+02:00] [debug] >>> testapi::wait_serial: # : fail
[2022-10-13T15:18:32.041731+02:00] [debug] tests/containers/apptainer.pm:50 called testapi::validate_script_output
[2022-10-13T15:18:32.041945+02:00] [debug] <<< distribution::script_output("Content of /tmp/script_uow4.sh :\n \"cat > /tmp/script_uow4.sh << 'EOT__uow4'; echo _uow4-\$?-\" \n")
[2022-10-13T15:18:32.043257+02:00] [debug] <<< consoles::serial_screen::type_string(text="cat > /tmp/script_uow4.sh << 'EOT__uow4'; echo _uow4-\$?-\n", json_cmd_token="kCaIjsnI", cmd="backend_type_string")
[2022-10-13T15:18:32.044126+02:00] [debug] tests/containers/apptainer.pm:50 called testapi::validate_script_output
[2022-10-13T15:18:32.044536+02:00] [debug] <<< testapi::wait_serial(quiet=1, record_output=undef, timeout=90, buffer_size=undef, expect_not_found=0, regexp="cat > /tmp/script_uow4.sh << 'EOT__uow4'; echo _uow4-\$?-", no_regex=1)
[2022-10-13T15:18:32.045981+02:00] [debug] <<< consoles::serial_screen::read_until(record_output=undef, timeout=90, no_regex=1, quiet=1, json_cmd_token="KTIlmTxF", cmd="backend_wait_serial", pattern=[
    "cat > /tmp/script_uow4.sh << 'EOT__uow4'; echo _uow4-\$?-"
  ], buffer_size=undef, regexp="cat > /tmp/script_uow4.sh << 'EOT__uow4'; echo _uow4-\$?-", expect_not_found=0)
[2022-10-13T15:18:32.046286+02:00] [info] ::: consoles::serial_screen::read_until: Matched output from SUT in 2 loops & 0.000667732208967209 seconds: cat > /tmp/script_uow4.sh << 'EOT__uow4'; echo _uow4-$?-
[2022-10-13T15:18:32.047033+02:00] [debug] >>> testapi::wait_serial: cat > /tmp/script_uow4.sh << 'EOT__uow4'; echo _uow4-$?-: ok
[2022-10-13T15:18:32.047315+02:00] [debug] tests/containers/apptainer.pm:50 called testapi::validate_script_output
[2022-10-13T15:18:32.047697+02:00] [debug] <<< testapi::wait_serial(record_output=undef, quiet=1, no_regex=1, expect_not_found=0, regexp="> ", buffer_size=undef, timeout=90)
[2022-10-13T15:18:32.049043+02:00] [debug] <<< consoles::serial_screen::read_until(no_regex=1, timeout=90, record_output=undef, expect_not_found=0, regexp="> ", buffer_size=undef, pattern=[
    "> "
  ], cmd="backend_wait_serial", json_cmd_token="TLLLRDQk", quiet=1)
[2022-10-13T15:18:32.049266+02:00] [info] ::: consoles::serial_screen::read_until: Matched output from SUT in 1 loops & 0.000562381930649281 seconds: > 
[2022-10-13T15:18:32.049970+02:00] [debug] >>> testapi::wait_serial: > : ok
[2022-10-13T15:18:32.050915+02:00] [debug] <<< consoles::serial_screen::type_string(text="cat /etc/os-release && echo testdone\nEOT__uow4\n", cmd="backend_type_string", json_cmd_token="KTMInCwi")
[2022-10-13T15:18:32.051701+02:00] [debug] tests/containers/apptainer.pm:50 called testapi::validate_script_output
[2022-10-13T15:18:32.052216+02:00] [debug] <<< testapi::wait_serial(regexp="> EOT__uow4", expect_not_found=0, no_regex=1, timeout=90, buffer_size=undef, record_output=undef, quiet=1)
[2022-10-13T15:18:32.053458+02:00] [debug] <<< consoles::serial_screen::read_until(json_cmd_token="azrXZuje", cmd="backend_wait_serial", quiet=1, expect_not_found=0, regexp="> EOT__uow4", pattern=[
    "> EOT__uow4"
  ], buffer_size=undef, record_output=undef, no_regex=1, timeout=90)
[2022-10-13T15:18:32.053728+02:00] [info] ::: consoles::serial_screen::read_until: Matched output from SUT in 2 loops & 0.000609030947089195 seconds: > EOT__uow4
[2022-10-13T15:18:32.054428+02:00] [debug] >>> testapi::wait_serial: > EOT__uow4: ok
[2022-10-13T15:18:32.054704+02:00] [debug] tests/containers/apptainer.pm:50 called testapi::validate_script_output
[2022-10-13T15:18:32.055060+02:00] [debug] <<< testapi::wait_serial(record_output=undef, quiet=1, no_regex=0, regexp="_uow4-0-", expect_not_found=0, buffer_size=undef, timeout=90)
[2022-10-13T15:18:32.056388+02:00] [debug] <<< consoles::serial_screen::read_until(timeout=90, no_regex=0, record_output=undef, pattern="_uow4-0-", buffer_size=undef, regexp="_uow4-0-", expect_not_found=0, quiet=1, cmd="backend_wait_serial", json_cmd_token="aCMENdVw")
[2022-10-13T15:18:32.058856+02:00] [info] ::: consoles::serial_screen::read_until: Matched output from SUT in 2 loops & 0.00273504760116339 seconds: _uow4-0-
[2022-10-13T15:18:32.059562+02:00] [debug] >>> testapi::wait_serial: _uow4-0-: ok
[2022-10-13T15:18:32.059848+02:00] [debug] tests/containers/apptainer.pm:50 called testapi::validate_script_output
[2022-10-13T15:18:32.060210+02:00] [debug] <<< testapi::wait_serial(expect_not_found=0, regexp="# ", no_regex=1, buffer_size=undef, timeout=90, record_output=undef, quiet=1)
[2022-10-13T15:18:32.061421+02:00] [debug] <<< consoles::serial_screen::read_until(buffer_size=undef, pattern=[
    "# "
  ], regexp="# ", expect_not_found=0, quiet=1, cmd="backend_wait_serial", json_cmd_token="HkXhwxdk", timeout=90, no_regex=1, record_output=undef)
[2022-10-13T15:20:02.113308+02:00] [debug] >>> testapi::wait_serial: # : fail
[2022-10-13T15:20:02.114530+02:00] [debug] <<< consoles::serial_screen::type_string(json_cmd_token="ZmelFHja", cmd="backend_type_string", text="echo _uow4; bash -oe pipefail /tmp/script_uow4.sh ; echo SCRIPT_FINISHED_uow4-\$?-\n")
[2022-10-13T15:20:02.115298+02:00] [debug] tests/containers/apptainer.pm:50 called testapi::validate_script_output
[2022-10-13T15:20:02.115764+02:00] [debug] <<< testapi::wait_serial(record_output=undef, quiet=1, no_regex=1, expect_not_found=0, regexp="echo _uow4; bash -oe pipefail /tmp/script_uow4.sh ; echo SCRIPT_FINISHED_uow4-\$?-", buffer_size=undef, timeout=90)
[2022-10-13T15:20:02.117013+02:00] [debug] <<< consoles::serial_screen::read_until(buffer_size=undef, pattern=[
    "echo _uow4; bash -oe pipefail /tmp/script_uow4.sh ; echo SCRIPT_FINISHED_uow4-\$?-"
  ], expect_not_found=0, regexp="echo _uow4; bash -oe pipefail /tmp/script_uow4.sh ; echo SCRIPT_FINISHED_uow4-\$?-", quiet=1, cmd="backend_wait_serial", json_cmd_token="HGtqBdRI", timeout=90, no_regex=1, record_output=undef)
[2022-10-13T15:20:02.117351+02:00] [info] ::: consoles::serial_screen::read_until: Matched output from SUT in 2 loops & 0.00069341529160738 seconds: echo _uow4; bash -oe pipefail /tmp/script_uow4.sh ; echo SCRIPT_FINISHED_uow4-$?-
[2022-10-13T15:20:02.118108+02:00] [debug] >>> testapi::wait_serial: echo _uow4; bash -oe pipefail /tmp/script_uow4.sh ; echo SCRIPT_FINISHED_uow4-$?-: ok
[2022-10-13T15:20:02.118391+02:00] [debug] tests/containers/apptainer.pm:50 called testapi::validate_script_output
[2022-10-13T15:20:02.118743+02:00] [debug] <<< testapi::wait_serial(expect_not_found=0, regexp="SCRIPT_FINISHED_uow4-\\d+-", no_regex=0, buffer_size=undef, timeout=90, record_output=1, quiet=1)
[2022-10-13T15:20:02.120085+02:00] [debug] <<< consoles::serial_screen::read_until(no_regex=0, timeout=90, record_output=1, expect_not_found=0, regexp="SCRIPT_FINISHED_uow4-\\d+-", buffer_size=undef, pattern="SCRIPT_FINISHED_uow4-\\d+-", cmd="backend_wait_serial", json_cmd_token="uwWUVyYC", quiet=1)
[2022-10-13T15:20:02.125432+02:00] [info] ::: consoles::serial_screen::read_until: Matched output from SUT in 8 loops & 0.00561576243489981 seconds: SCRIPT_FINISHED_uow4-0-
[2022-10-13T15:20:02.126191+02:00] [debug] >>> testapi::wait_serial: SCRIPT_FINISHED_uow4-\d+-: ok

I tried to play with set_serial_prompt and set_standard_prompt functions without actual solve the problem.
This isnt shown up when select_console is used

The failure comes from (script_output of distribution.pm)

testapi::wait_serial($self->{serial_term_prompt}, no_regex => 1, quiet => $args{quiet});

Expected:
wait_serial returns ok or ignore testapi::wait_serial if is an interactive terminal

Additional:
I think that this is low priority because doesnt make test fail or anything, but it would be nice to fix it and improve the code as it causes some additional time of the test execution without any good reason

Actions

Copy link

Updated by maritawerner over 1 year ago

Subject changed from wait_serial reports fail on serial_terminal when interactive cli is used to [qe-core] wait_serial reports fail on serial_terminal when interactive cli is used

Not sure who could take that, trying with qe-core

Actions

Copy link

Updated by slo-gin about 1 month ago

This ticket was set to Normal priority but was not updated within the SLO period. Please consider picking up this ticket or just set the ticket to the next lower priority.

Actions

Copy link

Also available in: Atom PDF

Project

General

Profile

QA » openQA Project » openQA Tests

Tags

Custom queries

action #118663

[qe-core] wait_serial reports fail on serial_terminal when interactive cli is used

Description¶

Updated by maritawerner over 1 year ago

Updated by slo-gin about 1 month ago