action #52235
closedisotovideo -d broken
0%
Description
This supposedly is a regression introduced in fe70160d7134dfa499cae7d47fafd95e5321dcf8
When running with -d to print debug output to stdout the autoinst-log.txt is never written as per
if ($direct_output) {
$logger = Mojo::Log->new(level => 'debug');
}
else {
$logger = Mojo::Log->new(level => 'debug', path => catfile(result_dir, 'autoinst-log.txt'));
}
which bastest.pm will eventually trip over in
# Detect autoinst failures and override result if die
try {
$self->search_for_expected_autoinst_failures();
}
catch {
# Process autoinst dectection failure
bmwqemu::diag($_);
$self->record_resultfile('Failed', $_, result => 'fail');
$died = 1;
};
output:
[2019-05-28T12:52:46.236 UTC] [debug] Can't open 'autoinst-log.txt' for reading: 'No such file or directory' at /workspace/os-autoinst/basetest.pm line 742
[2019-05-28T12:52:46.237 UTC] [debug] try() encountered an unexpected argument (1) - perhaps a missing semi-colon before or at /workspace/os-autoinst/basetest.pm line 391.
[2019-05-28T12:52:46.237 UTC] [debug] killing autotest process 34
Updated by coolo over 5 years ago
- Category set to Regressions/Crashes
- Assignee set to dheidler
- Priority changed from Normal to Urgent
- Target version set to Current Sprint
Then the log file needs to be written unconditionally - in addition to stderr
Updated by dheidler over 5 years ago
- Status changed from In Progress to Feedback
Updated by szarate over 5 years ago
- Related to action #52247: autoinst-log.txt opened with wrong path added
Updated by okurz over 5 years ago
so now we have every line doubled in https://openqa.opensuse.org/tests/948392/file/autoinst-log.txt . I don't think this is what you wanted.
Updated by dheidler over 5 years ago
It seems to behave differently depending on how it was started.
I didn't get the double log lines, when I called isotovideo from the commandline.
But it does when isotovideo is called by the openQA-worker.
Updated by dheidler over 5 years ago
I can reproduce the double log entries, when I run my test via openQA webui.
But I don't understand how isotovideo can inherit a log handle from openQA code, as openQA runs isotovideo as a subprocess as a command.
But still this is what seems to happen - when I comment out this lines in the openQA code, the problem with the double log lines goes away:
diff --git a/lib/OpenQA/Worker/Cache.pm b/lib/OpenQA/Worker/Cache.pm
index 5813f791..0a29e625 100644
--- a/lib/OpenQA/Worker/Cache.pm
+++ b/lib/OpenQA/Worker/Cache.pm
@@ -100,7 +100,7 @@ sub download_asset {
append_channel_to_defaults('autoinst');
}
else {
- add_log_channel('autoinst', path => 'autoinst-log.txt', level => 'debug', default => 'append');
+ #add_log_channel('autoinst', path => 'autoinst-log.txt', level => 'debug', default => 'append');
}
my $ua = Mojo::UserAgent->new(max_redirects => 2);
diff --git a/lib/OpenQA/Worker/Commands.pm b/lib/OpenQA/Worker/Commands.pm
index cf007c2a..23727aef 100644
--- a/lib/OpenQA/Worker/Commands.pm
+++ b/lib/OpenQA/Worker/Commands.pm
@@ -145,7 +145,7 @@ sub websocket_commands {
$OpenQA::Worker::Common::job = $job;
remove_log_channel('autoinst');
remove_log_channel('worker');
- add_log_channel('autoinst', path => 'autoinst-log.txt', level => 'debug');
+ #add_log_channel('autoinst', path => 'autoinst-log.txt', level => 'debug');
add_log_channel(
'worker',
path => 'worker-log.txt',
Updated by dheidler over 5 years ago
This should prevent openQA from getting the logs from isotovideo twice:
https://github.com/os-autoinst/openQA/pull/2092
Now isotovideo will log its own stuff and openQA will put everywhing that isotovideo spits out on stderr into the autoinst log additionally.
So the problem with the double lines should be solved without loosing previously existing log entries.
Updated by okurz over 5 years ago
- Related to action #45011: Allow detection of known failures at the autoinst-log.txt added
Updated by okurz over 5 years ago
- Status changed from Feedback to Resolved
We did not use the above PR but I created https://github.com/os-autoinst/os-autoinst/pull/1161 which was approved and merged partially reverting the changes done to get back into working state, that is proper output, no duplication, etc. Now we can try again to bring in the originally intended changes in #45011