diff --git a/cpanfile b/cpanfile
index f465a169d53..7c0bfed0b5f 100644
--- a/cpanfile
+++ b/cpanfile
@@ -90,7 +90,6 @@ requires 'diagnostics';
requires 'namespace::clean';
requires 'strict';
requires 'warnings';
-requires 'File::Path';
on 'test' => sub {
requires 'Perl::Tidy';
diff --git a/lib/OpenQA/Setup.pm b/lib/OpenQA/Setup.pm
index d5efa16f7e9..f21ef9f9f86 100644
--- a/lib/OpenQA/Setup.pm
+++ b/lib/OpenQA/Setup.pm
@@ -30,7 +30,7 @@ use File::Path 'make_path';
has config => sub { {} };
-has log => sub { Mojo::Log->new(handle => \*STDOUT, level => "debug"); };
+has log => sub { Mojo::Log->new(handle => \*STDOUT, level => "info"); };
has home => sub { Mojo::Home->new($ENV{MOJO_HOME} || '/') };
diff --git a/lib/OpenQA/Utils.pm b/lib/OpenQA/Utils.pm
index 89d5bccdd2e..4f768a95dcb 100644
--- a/lib/OpenQA/Utils.pm
+++ b/lib/OpenQA/Utils.pm
@@ -25,6 +25,7 @@ use Mojo::File 'path';
use IO::Handle;
use Scalar::Util 'blessed';
use Data::Dump 'pp';
+use Mojo::Log;
require Exporter;
our ($VERSION, @ISA, @EXPORT, @EXPORT_OK, %EXPORT_TAGS);
@@ -46,6 +47,9 @@ $VERSION = sprintf "%d.%03d", q$Revision: 1.12 $ =~ /(\d+)/g;
&log_info
&log_error
&log_fatal
+ add_log_channel
+ remove_log_channel
+ get_channel_handle
&save_base64_png
&run_cmd_with_log
&run_cmd_with_log_return_error
@@ -111,6 +115,8 @@ our $imagesdir = "$prjdir/images";
our $hostname = $ENV{SERVER_NAME};
our $app;
+my %channels = ();
+
# the desired new folder structure is
# $testcasedir/<testrepository>
# with "main.pm" and needles being in a productdir under <testrepository>
@@ -219,8 +225,12 @@ sub needle_info {
# logging helpers
sub log_debug {
- my ($msg) = @_;
- if ($app && $app->log) {
+ my ($msg, $channel) = @_;
+
+ if ($channel && $channels{$channel}) {
+ $channels{$channel}->debug($msg);
+ }
+ elsif ($app && $app->log) {
$app->log->debug($msg);
}
else {
@@ -229,8 +239,11 @@ sub log_debug {
}
sub log_info {
- my ($msg) = @_;
- if ($app && $app->log) {
+ my ($msg, $channel) = @_;
+ if ($channel && $channels{$channel}) {
+ $channels{$channel}->info($msg);
+ }
+ elsif ($app && $app->log) {
$app->log->info($msg);
}
else {
@@ -239,8 +252,11 @@ sub log_info {
}
sub log_warning {
- my ($msg) = @_;
- if ($app && $app->log) {
+ my ($msg, $channel) = @_;
+ if ($channel && $channels{$channel}) {
+ $channels{$channel}->warn($msg);
+ }
+ elsif ($app && $app->log) {
$app->log->warn($msg);
}
else {
@@ -249,8 +265,11 @@ sub log_warning {
}
sub log_error {
- my ($msg) = @_;
- if ($app && $app->log) {
+ my ($msg, $channel) = @_;
+ if ($channel && $channels{$channel}) {
+ $channels{$channel}->error($msg);
+ }
+ elsif ($app && $app->log) {
$app->log->error($msg);
}
else {
@@ -259,8 +278,11 @@ sub log_error {
}
sub log_fatal {
- my ($msg) = @_;
- if ($app && $app->log) {
+ my ($msg, $channel) = @_;
+ if ($channel && $channels{$channel}) {
+ $channels{$channel}->fatal($msg);
+ }
+ elsif ($app && $app->log) {
$app->log->fatal($msg);
}
else {
@@ -269,6 +291,26 @@ sub log_fatal {
die $msg;
}
+sub add_log_channel {
+ my ($channel, @options) = @_;
+ $channels{$channel} = Mojo::Log->new(@options);
+}
+
+sub remove_log_channel {
+ my ($channel) = @_;
+ delete $channels{$channel} if $channel;
+}
+
+sub get_channel_handle {
+ my ($channel) = @_;
+ if ($channel) {
+ return $channels{$channel}->handle if $channels{$channel};
+ }
+ elsif ($app) {
+ return $app->log->handle;
+ }
+}
+
sub save_base64_png($$$) {
my ($dir, $newfile, $png) = @_;
return unless $newfile;
diff --git a/lib/OpenQA/Worker/Cache.pm b/lib/OpenQA/Worker/Cache.pm
index 852f2f0bb2d..3ee2546ef7c 100644
--- a/lib/OpenQA/Worker/Cache.pm
+++ b/lib/OpenQA/Worker/Cache.pm
@@ -20,7 +20,7 @@ use warnings;
use File::Basename;
use Fcntl ':flock';
use Mojo::UserAgent;
-use OpenQA::Utils qw(log_error log_info log_debug);
+use OpenQA::Utils qw(log_error log_info log_debug get_channel_handle add_log_channel);
use OpenQA::Worker::Common;
use List::MoreUtils;
use File::Spec::Functions 'catdir';
@@ -82,12 +82,11 @@ sub init {
sub download_asset {
my ($id, $type, $asset, $etag) = @_;
- open(my $log, '>>', "autoinst-log.txt") or die("Cannot open autoinst-log.txt");
- local $| = 1;
+ add_log_channel('autoinst', path => 'autoinst-log.txt', level => 'debug') unless get_channel_handle('autoinst');
my $ua = Mojo::UserAgent->new(max_redirects => 2);
$ua->max_response_size(0);
my $url = sprintf '%s/tests/%d/asset/%s/%s', $host, $id, $type, basename($asset);
- print $log "Downloading " . basename($asset) . " from $url\n";
+ log_debug("Downloading " . basename($asset) . " from $url", 'autoinst');
my $tx = $ua->build_tx(GET => $url);
my $headers;
@@ -115,7 +114,7 @@ sub download_asset {
$last_updated = time;
if ($progress < $current) {
$progress = $current;
- print $log "CACHE: Downloading $asset: ", $size == $len ? 100 : $progress . "%\n";
+ log_debug("CACHE: Downloading $asset: ", $size == $len ? 100 : $progress . "%", 'autoinst');
}
}
});
@@ -126,20 +125,20 @@ sub download_asset {
my $size;
if ($code eq 304) {
if (toggle_asset_lock($asset, 0)) {
- print $log "CACHE: Content has not changed, not downloading the $asset but updating last use\n";
+ log_debug("CACHE: Content has not changed, not downloading the $asset but updating last use", 'autoinst');
}
else {
- print $log "CACHE: Abnormal situation, code 304. Retrying download\n"; # poo#19270 might give a hint
+ log_debug("CACHE: Abnormal situation, code 304. Retrying download", 'autoinst');
$asset = 520;
}
}
elsif ($tx->res->is_server_error) {
if (toggle_asset_lock($asset, 0)) {
- print $log "CACHE: Could not download the asset, triggering a retry for $code.\n";
+ log_debug("CACHE: Could not download the asset, triggering a retry for $code.", 'autoinst');
$asset = $code;
}
else {
- print $log "CACHE: Abnormal situation, server error. Retrying download\n";
+ log_debug("CACHE: Abnormal situation, server error. Retrying download", 'autoinst');
$asset = $code;
}
}
@@ -150,19 +149,18 @@ sub download_asset {
if ($size == $headers->content_length) {
check_limits($size);
update_asset($asset, $etag, $size);
- print $log "CACHE: Asset download successful to $asset, Cache size is: $cache_real_size\n";
+ log_debug("CACHE: Asset download successful to $asset, Cache size is: $cache_real_size", 'autoinst');
}
else {
- print $log "CACHE: Size of $asset differs, Expected: "
- . $headers->content_length
- . " / Downloaded: "
- . "$size \n";
+ log_debug(
+ "CACHE: Size of $asset differs, Expected: " . $headers->content_length . " / Downloaded: " . "$size",
+ 'autoinst');
$asset = 598; # 598 (Informal convention) Network read timeout error
}
}
else {
my $message = $tx->res->error->{message};
- print $log "CACHE: Download of $asset failed with: $code - $message\n";
+ log_debug("CACHE: Download of $asset failed with: $code - $message", 'autoinst');
purge_asset($asset);
$asset = undef;
}
diff --git a/lib/OpenQA/Worker/Commands.pm b/lib/OpenQA/Worker/Commands.pm
index c1e112034dd..ed357c8ec1b 100644
--- a/lib/OpenQA/Worker/Commands.pm
+++ b/lib/OpenQA/Worker/Commands.pm
@@ -17,7 +17,7 @@ package OpenQA::Worker::Commands;
use 5.018;
use warnings;
-use OpenQA::Utils qw(log_error log_warning log_debug);
+use OpenQA::Utils qw(log_error log_warning log_debug add_log_channel remove_log_channel);
use OpenQA::Worker::Common;
use OpenQA::Worker::Jobs;
use POSIX ':sys_wait_h';
@@ -158,6 +158,8 @@ sub websocket_commands {
if ($job && $job->{id}) {
$OpenQA::Worker::Common::job = $job;
+ remove_log_channel('autoinst');
+ add_log_channel('autoinst', path => 'autoinst-log.txt', level => 'debug');
log_debug("Job " . $job->{id} . " scheduled for next cycle");
Mojo::IOLoop->singleton->once(
"start_job" => sub {
diff --git a/lib/OpenQA/Worker/Engines/isotovideo.pm b/lib/OpenQA/Worker/Engines/isotovideo.pm
index 9f4b47edd0f..65ddc639dc0 100644
--- a/lib/OpenQA/Worker/Engines/isotovideo.pm
+++ b/lib/OpenQA/Worker/Engines/isotovideo.pm
@@ -18,7 +18,7 @@ use strict;
use warnings;
use OpenQA::Worker::Common;
-use OpenQA::Utils qw(locate_asset log_error log_info log_debug);
+use OpenQA::Utils qw(locate_asset log_error log_info log_debug get_channel_handle);
use POSIX qw(:sys_wait_h strftime uname _exit);
use JSON 'to_json';
@@ -29,6 +29,7 @@ use Errno;
use Cwd qw(abs_path getcwd);
use OpenQA::Worker::Cache;
use Time::HiRes 'sleep';
+use IO::Handle;
my $isotovideo = "/usr/bin/isotovideo";
my $workerpid;
@@ -119,13 +120,10 @@ sub detect_asset_keys {
sub engine_workit {
my ($job) = @_;
- if (open(my $log, '>', "autoinst-log.txt")) {
- print $log "+++ setup notes +++\n";
- printf $log "start time: %s\n", strftime("%F %T", gmtime);
- my ($sysname, $hostname, $release, $version, $machine) = POSIX::uname();
- printf $log "running on $hostname:%d ($sysname $release $version $machine)\n", $instance;
- close($log);
- }
+ my ($sysname, $hostname, $release, $version, $machine) = POSIX::uname();
+ log_debug('+++ setup notes +++', 'autoinst');
+ log_debug(sprintf("start time: %s", strftime("%F %T", gmtime)), 'autoinst');
+ log_debug(sprintf("running on $hostname:%d ($sysname $release $version $machine)", $instance), 'autoinst');
# set base dir to the one assigned with webui
OpenQA::Utils::change_sharedir($hosts->{$current_host}{dir});
@@ -213,15 +211,14 @@ sub engine_workit {
setpgrp(0, 0);
$ENV{TMPDIR} = $tmpdir;
log_info("$$: WORKING " . $job->{id});
- if (open(my $log, '>>', "autoinst-log.txt")) {
- print $log "+++ worker notes +++\n";
- printf $log "start time: %s\n", strftime("%F %T", gmtime);
- my ($sysname, $hostname, $release, $version, $machine) = POSIX::uname();
- printf $log "running on $hostname:%d ($sysname $release $version $machine)\n", $instance;
- close($log);
- }
- open STDOUT, ">>", "autoinst-log.txt";
- open STDERR, ">&STDOUT";
+ log_debug('+++ worker notes +++', 'autoinst');
+ log_debug(sprintf("start time: %s", strftime("%F %T", gmtime)), 'autoinst');
+
+ my ($sysname, $hostname, $release, $version, $machine) = POSIX::uname();
+ log_debug(sprintf("running on $hostname:%d ($sysname $release $version $machine)", $instance), 'autoinst');
+ my $handle = get_channel_handle('autoinst');
+ STDOUT->fdopen($handle, 'w');
+ STDERR->fdopen($handle, 'w');
exec "perl", "$isotovideo", '-d';
die "exec failed: $!\n";
}
diff --git a/lib/OpenQA/Worker/Jobs.pm b/lib/OpenQA/Worker/Jobs.pm
index 70ecdb4de38..80f1f45d7f1 100644
--- a/lib/OpenQA/Worker/Jobs.pm
+++ b/lib/OpenQA/Worker/Jobs.pm
@@ -126,7 +126,6 @@ sub check_job {
sub stop_job {
my ($aborted, $job_id) = @_;
-
# we call this function in all situations, so better check
if (!$job || $stop_job_running) {
# In case there is no job, or if the job was asked to stop
@@ -188,9 +187,7 @@ sub upload {
# we need to open and close the log here as one of the files
# might actually be autoinst-log.txt
- open(my $log, '>>', "autoinst-log.txt");
- printf $log "uploading %s\n", $filename;
- close $log;
+ log_debug("uploading $filename", 'autoinst');
log_debug("uploading $filename");
my $regular_upload_failed = 0;
@@ -228,10 +225,8 @@ sub upload {
# Just return if all upload retries have failed
# this will cause the next group of uploads to be triggered
- my $msg = "All $retry_limit upload attempts have failed for $filename\n";
- open(my $log, '>>', "autoinst-log.txt");
- print $log $msg;
- close $log;
+ my $msg = "All $retry_limit upload attempts have failed for $filename";
+ log_debug($msg, 'autoinst');
log_error($msg);
return 0;
}
@@ -246,9 +241,7 @@ sub upload {
else {
$msg = sprintf "ERROR %s: Connection error: $err->{message}\n", $filename;
}
- open(my $log, '>>', "autoinst-log.txt");
- print $log $msg;
- close $log;
+ log_debug($msg, 'autoinst');
log_error($msg);
return 0;
}
@@ -267,15 +260,15 @@ sub upload {
($csum2, $size2) = split(/ /, <$cfd>);
close($cfd);
}
- open(my $log, '>>', "autoinst-log.txt");
- print $log "Checksum comparison (actual:expected) $csum1:$csum2 with size (actual:expected) $size1:$size2\n";
+ log_debug("Checksum comparison (actual:expected) $csum1:$csum2 with size (actual:expected) $size1:$size2",
+ 'autoinst');
if ($csum1 eq $csum2 && $size1 eq $size2) {
my $ua_url = $hosts->{$current_host}{url}->clone;
$ua_url->path("jobs/$job_id/ack_temporary");
$hosts->{$current_host}{ua}->post($ua_url => form => {temporary => $res->res->json->{temporary}});
}
else {
- print $log "Checksum/size comparison of $filename FAILED\n";
+ log_debug("Checksum/size comparison of $filename FAILED", 'autoinst');
return 0;
}
}
@@ -318,13 +311,9 @@ sub _stop_job_2 {
$aborted ||= 'done';
my $job_done; # undef
-
- open(my $log, '>>', "autoinst-log.txt");
- print $log "+++ worker notes +++\n";
- printf $log "end time: %s\n", strftime("%F %T", gmtime);
- print $log "result: $aborted\n";
- close $log;
-
+ log_debug("+++ worker notes +++", 'autoinst');
+ log_debug(sprintf("end time: %s", strftime("%F %T", gmtime)), 'autoinst');
+ log_debug("result: $aborted", 'autoinst');
if ($aborted ne 'quit' && $aborted ne 'abort' && $aborted ne 'api-failure') {
# collect uploaded logs
my @uploaded_logfiles = glob "$pooldir/ulogs/*";
@@ -367,7 +356,6 @@ sub _stop_job_2 {
}
}
}
-
for my $file (qw(video.ogv vars.json serial0 autoinst-log.txt virtio_console.log)) {
next unless -e $file;
# default serial output file called serial0
diff --git a/t/24-worker.t b/t/24-worker.t
index e1826893eda..cb480052196 100644
--- a/t/24-worker.t
+++ b/t/24-worker.t
@@ -27,7 +27,7 @@ use OpenQA::Client;
use Test::More;
use Test::Mojo;
use Test::Warnings;
-use Test::Output qw(stdout_like stderr_like);
+use Test::Output 'combined_like';
use Test::Fatal;
use Mojo::File qw(tempdir path);
#use Scalar::Utils 'refaddr';
@@ -97,7 +97,7 @@ test_via_io_loop sub {
tries => 1,
callback => sub { my $res = shift; is($res, undef, 'error ignored') });
- stderr_like(
+ combined_like(
sub {
OpenQA::Worker::Common::api_call(
'post', 'jobs/500/status',
@@ -106,7 +106,7 @@ test_via_io_loop sub {
callback => sub { my $res = shift; is($res, undef, 'error handled'); Mojo::IOLoop->stop() });
while (Mojo::IOLoop->is_running) { Mojo::IOLoop->singleton->reactor->one_tick }
},
- qr/.*\[ERROR\] Connection error:.*(remaining tries: 0).*/i,
+ qr/.*\[ERROR\] Connection error:.*(remaining tries: 0).*\[DEBUG\] .* no job running.*/s,
'warning about 503 error'
);
};
diff --git a/t/25-cache.t b/t/25-cache.t
index 8c087d2bff5..1d221b017ea 100644
--- a/t/25-cache.t
+++ b/t/25-cache.t
@@ -69,6 +69,7 @@ sub truncate_log {
my $logfile_ = ($new_log) ? $new_log : $logfile;
open(my $f, '>', $logfile_) or die "OPENING $logfile_: $!\n";
truncate $f, 0 or warn("Could not truncate");
+ close $f;
}
sub read_log {
diff --git a/t/28-logging.t b/t/28-logging.t
index bab3642b78d..6cab94b0e4d 100644
--- a/t/28-logging.t
+++ b/t/28-logging.t
@@ -20,18 +20,18 @@ BEGIN {
}
use Test::More;
use Mojo::File qw(tempdir tempfile);
-use OpenQA::Utils qw(log_error log_warning log_fatal log_info log_debug);
+use OpenQA::Utils qw(log_error log_warning log_fatal log_info log_debug add_log_channel);
use OpenQA::Setup;
use File::Path qw(make_path remove_tree);
use Sys::Hostname;
use File::Spec::Functions 'catfile';
-my $reFile = qr/\[.*?\] \[worker:(.*)\] (.*) message/;
-my $reStdOut = qr/(?:.*?)\[worker:(.*)\] (.*) message/;
-
+my $reFile = qr/\[.*?\] \[worker:(.*?)\] (.*?) message/;
+my $reStdOut = qr/(?:.*?)\[worker:(.*?)\] (.*?) message/;
+my $reChannel = qr/\[.*?\] \[(.*?)\] (.*?) message/;
subtest 'Logging to stdout' => sub {
- delete $ENV{OPENQA_WORKER_LOGDIR};
- delete $ENV{OPENQA_LOGFILE};
+ local $ENV{OPENQA_WORKER_LOGDIR};
+ local $ENV{OPENQA_LOGFILE};
# Capture STDOUT:
# 1- dups the current STDOUT to $oldSTDOUT. This is used to restore the STDOUT later
# 2- Closes the current STDOUT
@@ -51,7 +51,7 @@ subtest 'Logging to stdout' => sub {
);
$app->setup_log();
- # $OpenQA::Utils::app = $app;
+
log_debug('debug message');
log_error('error message');
log_info('info message');
@@ -81,7 +81,6 @@ subtest 'Logging to file' => sub {
);
my $output_logfile = catfile($ENV{OPENQA_WORKER_LOGDIR}, hostname() . '-1.log');
$app->setup_log();
- # $OpenQA::Utils::app = $app;
log_debug('debug message');
log_error('error message');
log_info('info message');
@@ -141,16 +140,17 @@ subtest 'Checking log level' => sub {
my $output_logfile = catfile($ENV{OPENQA_WORKER_LOGDIR}, hostname() . '-1.log');
- my @loglevels = qw(debug info warn error fatal);
- my $deathcounter = 0;
- my $counter = @loglevels;
- for (@loglevels) {
+ my @loglevels = qw(debug info warn error fatal);
+ my $deathcounter = 0;
+ my $counterFile = @loglevels;
+ my $counterChannel = @loglevels;
+ for my $level (@loglevels) {
my $app = OpenQA::Setup->new(
mode => 'production',
log_name => 'worker',
instance => 1,
log_dir => $ENV{OPENQA_WORKER_LOGDIR},
- level => $_
+ level => $level
);
$app->setup_log();
@@ -161,16 +161,49 @@ subtest 'Checking log level' => sub {
log_warning('warn message');
log_error('error message');
- my $exception = 0;
eval { log_fatal('fatal message'); };
$deathcounter++ if $@;
my %matches = map { $_ => 1 } (Mojo::File->new($output_logfile)->slurp =~ m/$reFile/gm);
- ok(keys(%matches) == $counter--, "Worker log level $_ entry");
+ ok(keys(%matches) == $counterFile, "Worker log level $level entry");
+
+ my $logging_test_file = tempfile;
+
+ add_log_channel('test', path => $logging_test_file, level => $level);
+ log_debug("debug message", 'test');
+ log_info("info message", 'test');
+ log_warning("warn message", 'test');
+ log_error("error message", 'test');
+
+ eval { log_fatal('fatal message', 'test'); };
+ $deathcounter++ if $@;
+
+ %matches = map { $_ => 1 } (Mojo::File->new($logging_test_file)->slurp =~ m/$reChannel/gm);
+ ok(keys(%matches) == $counterChannel--, "Worker channel log level $level entry"); # TODO
+ # use Data::Dumper;
+ # print Dumper(\%matches);
+ # unlink $logging_test_file;
+
+ log_debug("debug message", 'no_channel');
+ log_info("info message", 'no_channel');
+ log_warning("warn message", 'no_channel');
+ log_error("error", 'no_channel');
+
+ eval { log_fatal('fatal message', 'no_channel'); };
+
+ $deathcounter++ if $@;
+
+ # print Mojo::File->new($output_logfile)->slurp;
+
+ %matches = map { $_ => ($matches{$_} // 0) + 1 } (Mojo::File->new($output_logfile)->slurp =~ m/$reFile/gm);
+ my @vals = grep { $_ != 2 } (values(%matches));
+ ok(keys(%matches) == $counterFile--, "Worker no existent channel log level $level entry");
+ ok(@vals == 0, 'Worker no existent channel log level $level entry ');
+
truncate $output_logfile, 0;
}
- ok($deathcounter == @loglevels, "Worker dies when logs fatal");
+ ok($deathcounter / 3 == @loglevels, "Worker dies when logs fatal");
# clear the system
remove_tree $ENV{OPENQA_WORKER_LOGDIR};
@@ -232,5 +265,4 @@ subtest 'Logging to right place' => sub {
delete $ENV{OPENQA_WORKER_LOGDIR};
};
-
done_testing;
diff --git a/t/api/04-jobs.t b/t/api/04-jobs.t
index 9852aac8bc4..1d67b90dd7b 100644
--- a/t/api/04-jobs.t
+++ b/t/api/04-jobs.t
@@ -279,6 +279,62 @@ $get = $t->get_ok($query->path_query)->status_is(200);
$res = $get->tx->res->json;
ok(!@{$res->{jobs}}, 'no result for nonexising state');
+subtest 'Check job status and output' => sub {
+ $get = $t->get_ok('/api/v1/jobs');
+ @new_jobs = @{$get->tx->res->json->{jobs}};
+ my $running_job_id;
+
+ local $ENV{MOJO_LOG_LEVEL} = 'debug';
+ local $ENV{OPENQA_LOGFILE};
+ local $ENV{OPENQA_WORKER_LOGDIR};
+ $OpenQA::Utils::app->log(Mojo::Log->new(handle => \*STDOUT));
+
+ for my $job (@new_jobs) {
+ my $worker_id = $job->{assigned_worker_id};
+ my $json = {};
+ if ($worker_id) {
+ $json->{status} = {worker_id => $worker_id};
+ $running_job_id = $job->{id};
+ }
+
+ open(my $oldSTDOUT, ">&", STDOUT) or die "Can't preserve STDOUT\n$!\n";
+ close STDOUT;
+ my $output;
+ open STDOUT, '>', \$output;
+
+
+ $post = $t->post_ok("/api/v1/jobs/$job->{id}/status", json => $json);
+ $worker_id = 0;
+ close STDOUT;
+ open(STDOUT, '>&', $oldSTDOUT) or die "Can't dup \$oldSTDOUT: $!";
+ if ($job->{id} == 99963) {
+ $post->status_is(200);
+ }
+ else {
+ $post->status_is(400);
+ ok($output =~ /\[.*info\] Got status update for job .*? but does not contain a worker id!/,
+ "Check status update for job $job->{id}");
+ }
+ }
+
+ open(my $oldSTDOUT, ">&", STDOUT) or die "Can't preserve STDOUT\n$!\n";
+ close STDOUT;
+ my $output;
+ open STDOUT, '>', \$output;
+ # bogus job ID
+ my $bogus_job_post = $t->post_ok("/api/v1/jobs/9999999/status", json => {});
+ # bogus worker ID
+ my $bogus_worker_post
+ = $t->post_ok("/api/v1/jobs/$running_job_id/status", json => {status => {worker_id => 999999}});
+ close STDOUT;
+ open(STDOUT, '>&', $oldSTDOUT) or die "Can't dup \$oldSTDOUT: $!";
+
+ $bogus_job_post->status_is(400);
+ $bogus_worker_post->status_is(400);
+ ok($output =~ /\[.*info\] Got status update for non-existing job/, 'Check status update for non-existing job');
+ ok($output =~ /\[.*info\] Got status update for job .* that does not belong to Worker/,
+ 'Got status update for job that doesnt belong to worker');
+};
# Test /jobs/cancel
# TODO: cancelling jobs via API in tests doesn't work for some reason
#
diff --git a/t/full-stack.t b/t/full-stack.t
index 1a94b0386cc..a4cae5a142b 100644
--- a/t/full-stack.t
+++ b/t/full-stack.t
@@ -280,11 +280,19 @@ wait_for_result_panel qr/Result: incomplete/, 'Test 4 crashed as expected';
# Slurp the whole file, it's not that big anyways
my $filename = $resultdir . "/00000/00000004-$job_name/autoinst-log.txt";
+ok(-s $filename, 'Test 4 autoinst-log.txt file created');
open(my $f, '<', $filename) or die "OPENING $filename: $!\n";
my $autoinst_log = do { local ($/); <$f> };
close($f);
like($autoinst_log, qr/result: setup failure/, 'Test 4 state correct: setup failure');
+
+like((split(/\n/, $autoinst_log))[0], qr/\[debug\] \+\+\+ setup notes \+\+\+/, 'Test 4 correct autoinst setup notes');
+like(
+ (split(/\n/, $autoinst_log))[-1],
+ qr/\[debug\] uploading autoinst-log.txt/,
+ 'Test 4 correct autoinst uploading autoinst'
+);
kill_worker; # Ensure that the worker can be killed with TERM signal
my $cache_location = path($ENV{OPENQA_BASEDIR}, 'cache')->make_path;
@@ -341,7 +349,18 @@ subtest 'Cache tests' => sub {
close($f);
like($autoinst_log, qr/Downloading Core-7.2.iso/, 'Test 5, downloaded the right iso.');
- like($autoinst_log, qr/11116544/, 'Test 5 Core-7.2.iso size is correct.');
+ like($autoinst_log, qr/11116544/, 'Test 5 Core-7.2.iso size is correct.');
+ like($autoinst_log, qr/\[debug\] result: done/, 'Test 5 result done');
+ like(
+ (split(/\n/, $autoinst_log))[0],
+ qr/\[debug\] \+\+\+ setup notes \+\+\+/,
+ 'Test 5 correct autoinst setup notes'
+ );
+ like(
+ (split(/\n/, $autoinst_log))[-1],
+ qr/\[debug\] uploading autoinst-log.txt/,
+ 'Test 5 correct autoinst uploading autoinst'
+ );
my $dbh
= DBI->connect("dbi:SQLite:dbname=$db_file", undef, undef, {RaiseError => 1, PrintError => 1, AutoCommit => 1});
@@ -401,21 +420,47 @@ subtest 'Cache tests' => sub {
wait_for_result_panel qr/Result: passed/, 'test 7 is passed';
$filename = path($resultdir, '00000', "00000007-$job_name")->child("autoinst-log.txt");
+ ok(-s $filename, 'Test 7 autoinst-log.txt file created');
+
open($f, '<', $filename) or die "OPENING $filename: $!\n";
$autoinst_log = do { local ($/); <$f> };
close($f);
like($autoinst_log, qr/Content has not changed/, 'Test 7 Core-7.2.iso has not changed.');
+ like($autoinst_log, qr/\[debug\] \+\+\+\ worker notes \+\+\+/, 'Test 7 correct autoinst worker notes');
+ like(
+ (split(/\n/, $autoinst_log))[0],
+ qr/\[debug\] \+\+\+ setup notes \+\+\+/,
+ 'Test 7 correct autoinst setup notes'
+ );
+ like(
+ (split(/\n/, $autoinst_log))[-1],
+ qr/\[debug\] uploading autoinst-log.txt/,
+ 'Test 7 correct autoinst uploading autoinst'
+ );
client_call("jobs post $JOB_SETUP HDD_1=non-existent.qcow2");
$driver->get('/tests/8');
wait_for_result_panel qr/Result: incomplete/, 'test 8 is incomplete';
-
$filename = path($resultdir, '00000', "00000008-$job_name")->child("autoinst-log.txt");
+ ok(-s $filename, 'Test 8 autoinst-log.txt file created');
+
open($f, '<', $filename) or die "OPENING $filename: $!\n";
$autoinst_log = do { local ($/); <$f> };
close($f);
+ like($autoinst_log, qr/\[debug\] \+\+\+\ worker notes \+\+\+/, 'Test 7 correct autoinst worker notes');
+ like(
+ (split(/\n/, $autoinst_log))[0],
+ qr/\[debug\] \+\+\+ setup notes \+\+\+/,
+ 'Test 8 correct autoinst setup notes'
+ );
+ like(
+ (split(/\n/, $autoinst_log))[-1],
+ qr/\[debug\] uploading autoinst-log.txt/,
+ 'Test 8 correct autoinst uploading autoinst'
+ );
+
like($autoinst_log, qr/non-existent.qcow2 failed with: 404 - Not Found/, 'Test 8 failure message found in log.');
like($autoinst_log, qr/result: setup failure/, 'Test 8 state correct: setup failure');