diff --git a/lib/OpenQA/FakeApp.pm b/lib/OpenQA/FakeApp.pm
deleted file mode 100644
index 07345c4d7e7..00000000000
--- a/lib/OpenQA/FakeApp.pm
+++ /dev/null
@@ -1,72 +0,0 @@
-# Copyright (C) 2016 SUSE LLC
-#
-# This program is free software; you can redistribute it and/or modify
-# it under the terms of the GNU General Public License as published by
-# the Free Software Foundation; either version 2 of the License, or
-# (at your option) any later version.
-#
-# This program is distributed in the hope that it will be useful,
-# but WITHOUT ANY WARRANTY; without even the implied warranty of
-# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
-# GNU General Public License for more details.
-#
-# You should have received a copy of the GNU General Public License along
-# with this program; if not, see .
-
-package OpenQA::FakeApp;
-use Mojo::Log;
-use Mojo::Home;
-use strict;
-use warnings;
-use Mojo::Base -base;
-use Sys::Hostname;
-use File::Spec::Functions 'catfile';
-use Mojo::File 'path';
-
-has config => sub { {} };
-
-has log => sub { Mojo::Log->new(handle => \*STDOUT, level => "debug"); };
-
-has home => sub { Mojo::Home->new($ENV{MOJO_HOME} || '/') };
-
-has mode => 'production';
-
-has log_name => 'scheduler';
-
-has level => 'info';
-
-has instance => undef;
-
-has log_dir => undef;
-
-has schema => sub { OpenQA::Schema::connect_db() };
-
-sub setup_log {
- my ($self) = @_;
- if ($self->log_dir) {
- # So each worker from each host get it's own log (as the folder can be shared). Hopefully the machine hostname
- # is already sanitized. Otherwise we need to check
- my $logfile
- = catfile($self->log_dir, hostname() . (defined $self->instance ? "-${\$self->instance}" : '') . ".log");
-
- $self->log->handle(path($logfile)->open('>>'));
-
- $self->log->path($logfile);
- }
-
- $self->log->format(
- sub {
- my ($time, $level, @lines) = @_;
- return '[' . localtime($time) . "] [${\$self->log_name}:$level] " . join "\n", @lines, '';
- });
-
- $self->log->level($self->level);
-}
-
-
-sub emit_event {
- my ($self, $event, $data) = @_;
- # nothing to see here, move along
-}
-
-1;
diff --git a/lib/OpenQA/ResourceAllocator.pm b/lib/OpenQA/ResourceAllocator.pm
index a5cbbca9683..420cbf158e4 100644
--- a/lib/OpenQA/ResourceAllocator.pm
+++ b/lib/OpenQA/ResourceAllocator.pm
@@ -25,10 +25,9 @@ use Scalar::Util 'blessed';
use OpenQA::IPC;
use OpenQA::Utils qw(log_debug wakeup_scheduler exists_worker safe_call);
-use OpenQA::ServerStartup;
use OpenQA::Resource::Jobs ();
use OpenQA::Resource::Locks ();
-use OpenQA::FakeApp;
+use OpenQA::Setup;
use sigtrap handler => \&normal_signals_handler, 'normal-signals';
my $singleton;
@@ -59,9 +58,9 @@ sub new {
sub run {
my $self = shift;
- my $fakeapp = OpenQA::FakeApp->new(log_name => 'resource-allocator');
- OpenQA::ServerStartup::read_config($fakeapp);
- OpenQA::ServerStartup::setup_logging($fakeapp);
+ my $setup = OpenQA::Setup->new(log_name => 'resource-allocator');
+ OpenQA::Setup::read_config($setup);
+ OpenQA::Setup::setup_log($setup);
log_debug("Resource allocator started");
$self->{reactor}->run()
if exists $self->{reactor} && blessed($self->{reactor}) && $self->{reactor}->isa("Net::DBus::Reactor");
diff --git a/lib/OpenQA/Scheduler.pm b/lib/OpenQA/Scheduler.pm
index 4fae36bc139..e7dc3d133af 100644
--- a/lib/OpenQA/Scheduler.pm
+++ b/lib/OpenQA/Scheduler.pm
@@ -23,10 +23,9 @@ use Net::DBus::Reactor;
use Data::Dump 'pp';
use OpenQA::IPC;
-use OpenQA::FakeApp;
+use OpenQA::Setup;
use OpenQA::Utils 'log_debug';
-use OpenQA::ServerStartup;
# How many jobs to allocate in one tick. Defaults to 50 ( set it to 0 for as much as possible)
use constant MAX_JOB_ALLOCATION => $ENV{OPENQA_SCHEDULER_MAX_JOB_ALLOCATION} // 50;
@@ -75,11 +74,11 @@ sub _is_method_allowed {
return $ret;
}
-our $fakeapp;
+our $setup;
sub run {
- $fakeapp = OpenQA::FakeApp->new;
- OpenQA::ServerStartup::read_config($fakeapp);
- OpenQA::ServerStartup::setup_logging($fakeapp);
+ $setup = OpenQA::Setup->new(log_name => 'scheduler');
+ OpenQA::Setup::read_config($setup);
+ OpenQA::Setup::setup_log($setup);
OpenQA::Scheduler->new();
log_debug("Scheduler started");
diff --git a/lib/OpenQA/ServerStartup.pm b/lib/OpenQA/Setup.pm
similarity index 63%
rename from lib/OpenQA/ServerStartup.pm
rename to lib/OpenQA/Setup.pm
index 02fba3d0237..f21ef9f9f86 100644
--- a/lib/OpenQA/ServerStartup.pm
+++ b/lib/OpenQA/Setup.pm
@@ -1,4 +1,4 @@
-# Copyright (C) 2015-2016 SUSE LLC
+# Copyright (C) 2017 SUSE LLC
#
# This program is free software; you can redistribute it and/or modify
# it under the terms of the GNU General Public License as published by
@@ -13,20 +13,117 @@
# You should have received a copy of the GNU General Public License along
# with this program; if not, see .
-# This package contains shared functions between WebAPI and WebSockets
-package OpenQA::ServerStartup;
-
+package OpenQA::Setup;
+use Mojo::Log;
+use Mojo::Home;
use strict;
use warnings;
+use Mojo::Base -base;
+use Sys::Hostname;
+use File::Spec::Functions 'catfile';
+use Mojo::File 'path';
use Config::IniFiles;
use db_profiler;
use db_helpers;
use OpenQA::Utils;
-use Mojo::File 'path';
+use File::Path 'make_path';
-sub read_config {
- my $app = shift;
+has config => sub { {} };
+
+has log => sub { Mojo::Log->new(handle => \*STDOUT, level => "info"); };
+
+has home => sub { Mojo::Home->new($ENV{MOJO_HOME} || '/') };
+
+has mode => 'production';
+
+has 'log_name';
+
+has level => 'info';
+
+has 'instance';
+
+has 'log_dir';
+
+has schema => sub { OpenQA::Schema::connect_db() };
+
+sub setup_log {
+ my ($self) = @_;
+ my ($logfile, $logdir, $level, $log);
+
+ if ($self->isa('OpenQA::Setup')) {
+ $logdir = $self->log_dir;
+ $level = $self->level;
+ if ($logdir && !-e $logdir) {
+ make_path($logdir);
+ }
+ elsif ($logdir && !-d $logdir) {
+ die "Please point the logs to a valid folder!";
+ }
+ }
+ else {
+ $log = $self->log;
+ $level = $self->config->{logging}->{level} || 'debug';
+ }
+ $logfile = $ENV{OPENQA_LOGFILE} || $self->config->{logging}->{file};
+
+ if ($logfile && $logdir) {
+ $logfile = catfile($logdir, $logfile);
+ $log = Mojo::Log->new(
+ handle => path($logfile)->open('>>'),
+ level => $self->level,
+ format => sub { return log_format($self->log_name, @_); });
+ }
+ elsif ($logfile) {
+ $log = Mojo::Log->new(
+ handle => path($logfile)->open('>>'),
+ level => $level,
+ format => sub { return log_format($self->log_name, @_); });
+ }
+ elsif ($logdir) {
+ # So each worker from each host get it's own log (as the folder can be shared). Hopefully the machine hostname
+ # is already sanitized. Otherwise we need to check
+ $logfile
+ = catfile($logdir, hostname() . (defined $self->instance ? "-${\$self->instance}" : '') . ".log");
+ $log = Mojo::Log->new(
+ handle => path($logfile)->open('>>'),
+ level => $self->level,
+ format => sub { return log_format($self->log_name, @_); });
+ }
+ else {
+ $log = Mojo::Log->new(
+ handle => \*STDOUT,
+ level => $level,
+ format => sub {
+ my ($time, $level, @lines) = @_;
+ return "[${\$self->log_name}:$level] " . join "\n", @lines, '';
+ });
+ }
+
+ $self->log($log);
+ unless ($self->isa('OpenQA::Setup')) {
+ if ($ENV{OPENQA_SQL_DEBUG} // $self->config->{logging}->{sql_debug} // 'false' eq 'true') {
+ # avoid enabling the SQL debug unless we really want to see it
+ # it's rather expensive
+ db_profiler::enable_sql_debugging($self);
+ }
+ }
+ $OpenQA::Utils::app = $self;
+ return $log;
+}
+
+sub log_format {
+ my ($logname, $time, $level, @lines) = @_;
+ return '[' . localtime($time) . "] [$logname:$level] " . join "\n", @lines, '';
+}
+
+sub emit_event {
+ my ($self, $event, $data) = @_;
+ # nothing to see here, move along
+}
+
+sub read_config {
+ my $app = shift;
my %defaults = (
global => {
appname => 'openQA',
@@ -123,41 +220,6 @@ sub read_config {
$app->config->{auth}->{method} =~ s/\s//g;
}
-sub setup_logging {
- my ($app) = @_;
-
- my $config = $app->config;
- my $logfile = $ENV{OPENQA_LOGFILE} || $config->{logging}->{file};
-
- if ($logfile) {
- $app->log->handle(path($logfile)->open('>>'));
- $app->log->path($logfile);
- $app->log->format(
- sub {
- my ($time, $level, @lines) = @_;
- return '[' . localtime($time) . "] [" . $app->log_name . ":$level] " . join "\n", @lines, '';
- });
- }
- else {
- $app->log->format(
- sub {
- my (undef, $level, @lines) = @_;
- return '[' . $app->log_name . ":$level] " . join "\n", @lines, '';
- });
- }
-
- if ($config->{logging}->{level}) {
- $app->log->level($config->{logging}->{level});
- }
- if ($ENV{OPENQA_SQL_DEBUG} // $config->{logging}->{sql_debug} // 'false' eq 'true') {
- # avoid enabling the SQL debug unless we really want to see it
- # it's rather expensive
- db_profiler::enable_sql_debugging($app);
- }
-
- $OpenQA::Utils::app = $app;
-}
-
# Update config definition from plugin requests
sub update_config {
my ($config, @namespaces) = @_;
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/
# with "main.pm" and needles being in a productdir under
@@ -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/WebAPI.pm b/lib/OpenQA/WebAPI.pm
index a3ab55f098a..5e5f0eb3c67 100644
--- a/lib/OpenQA/WebAPI.pm
+++ b/lib/OpenQA/WebAPI.pm
@@ -21,8 +21,7 @@ use OpenQA::Schema;
use OpenQA::WebAPI::Plugin::Helpers;
use OpenQA::IPC;
use OpenQA::Utils qw(log_warning job_groups_and_parents detect_current_version);
-use OpenQA::ServerStartup;
-
+use OpenQA::Setup;
use Mojo::IOLoop;
use Mojolicious::Commands;
use DateTime;
@@ -69,9 +68,8 @@ sub log_name {
# This method will run once at server start
sub startup {
my $self = shift;
-
- OpenQA::ServerStartup::read_config($self);
- OpenQA::ServerStartup::setup_logging($self);
+ OpenQA::Setup::read_config($self);
+ OpenQA::Setup::setup_log($self);
# Set some application defaults
$self->defaults(appname => $self->app->config->{global}->{appname});
@@ -127,7 +125,7 @@ sub startup {
}
# Read configurations expected by plugins.
- OpenQA::ServerStartup::update_config($self->config, @{$self->plugins->namespaces}, "OpenQA::WebAPI::Auth");
+ OpenQA::Setup::update_config($self->config, @{$self->plugins->namespaces}, "OpenQA::WebAPI::Auth");
# End plugin loading/handling
diff --git a/lib/OpenQA/WebSockets/Server.pm b/lib/OpenQA/WebSockets/Server.pm
index 6fb21b595c6..f93875fe481 100644
--- a/lib/OpenQA/WebSockets/Server.pm
+++ b/lib/OpenQA/WebSockets/Server.pm
@@ -21,7 +21,7 @@ use Try::Tiny;
use OpenQA::IPC;
use OpenQA::Utils qw(log_debug log_warning log_error);
use OpenQA::Schema;
-use OpenQA::ServerStartup;
+use OpenQA::Setup;
use Data::Dumper;
use Data::Dump 'pp';
use db_profiler;
@@ -458,9 +458,8 @@ sub setup {
app->helper(log_name => sub { return 'websockets' });
app->helper(schema => sub { return OpenQA::Schema::connect_db; });
-
- OpenQA::ServerStartup::read_config(app);
- OpenQA::ServerStartup::setup_logging(app);
+ OpenQA::Setup::read_config(app);
+ OpenQA::Setup::setup_log(app);
# not really meaningful for websockets, but required for mode defaults
app->defaults(appname => "openQA Websocket Server");
diff --git a/lib/OpenQA/Worker.pm b/lib/OpenQA/Worker.pm
index 107aa57a065..008781db6ff 100644
--- a/lib/OpenQA/Worker.pm
+++ b/lib/OpenQA/Worker.pm
@@ -30,7 +30,7 @@ use OpenQA::Worker::Common;
use OpenQA::Worker::Commands;
use OpenQA::Worker::Pool qw(lockit clean_pool);
use OpenQA::Worker::Jobs;
-use OpenQA::FakeApp;
+use OpenQA::Setup;
sub init {
my ($host_settings, $options) = @_;
@@ -39,7 +39,7 @@ sub init {
$nocleanup = $options->{"no-cleanup"};
my $logdir = $ENV{OPENQA_WORKER_LOGDIR} // $worker_settings->{LOG_DIR};
- my $app = OpenQA::FakeApp->new(
+ my $app = OpenQA::Setup->new(
mode => 'production',
log_name => 'worker',
instance => $instance,
@@ -48,7 +48,6 @@ sub init {
$app->level($worker_settings->{LOG_LEVEL}) if $worker_settings->{LOG_LEVEL};
$app->setup_log();
- $OpenQA::Utils::app = $app;
OpenQA::Worker::Common::api_init($host_settings, $options);
OpenQA::Worker::Engines::isotovideo::set_engine_exec($options->{isotovideo}) if $options->{isotovideo};
}
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/04-scheduler.t b/t/04-scheduler.t
index 2862b953ddd..2b3a5dce449 100644
--- a/t/04-scheduler.t
+++ b/t/04-scheduler.t
@@ -429,15 +429,14 @@ is_deeply(
my $asset = $schema->resultset('Assets')->register('iso', $settings{ISO});
is($asset->name, $settings{ISO}, "asset register returns same");
-subtest 'OpenQA::FakeApp object test' => sub {
- use OpenQA::FakeApp;
- use OpenQA::ServerStartup;
- my $fakeapp = OpenQA::FakeApp->new;
- OpenQA::ServerStartup::read_config($fakeapp);
- OpenQA::ServerStartup::setup_logging($fakeapp);
- isa_ok($fakeapp->home, 'Mojo::Home');
- isa_ok($fakeapp->schema, 'OpenQA::Schema');
- isa_ok($fakeapp->log, 'Mojo::Log');
+subtest 'OpenQA::Setup object test' => sub {
+ use OpenQA::Setup;
+ my $setup = OpenQA::Setup->new;
+ OpenQA::Setup::read_config($setup);
+ OpenQA::Setup::setup_log($setup);
+ isa_ok($setup->home, 'Mojo::Home');
+ isa_ok($setup->schema, 'OpenQA::Schema');
+ isa_ok($setup->log, 'Mojo::Log');
};
done_testing;
diff --git a/t/05-scheduler-full.t b/t/05-scheduler-full.t
index 2a83a117433..a230a427f3a 100644
--- a/t/05-scheduler-full.t
+++ b/t/05-scheduler-full.t
@@ -278,17 +278,18 @@ subtest 'Simulation of heavy unstable load' => sub {
subtest 'Websocket server - close connection test' => sub {
kill_service($wspid);
- my $log_file = tempfile;
+ my $log_file = tempfile;
+ local $ENV{OPENQA_LOGFILE};
+ local $ENV{MOJO_LOG_LEVEL};
my $unstable_ws_pid = create_websocket_server($mojoport + 1, 1);
- my $w2_pid = create_worker($k->key, $k->secret, "http://localhost:$mojoport", 2, $log_file);
- my $re = qr/\[.*?\]\sConnection turned off from .*?\- (.*?)\s\:(.*?) dead/;
+ my $w2_pid = create_worker($k->key, $k->secret, "http://localhost:$mojoport", 2, $log_file);
+ my $re = qr/\[.*?\]\sConnection turned off from .*?\- (.*?)\s\:(.*?) dead/;
my $attempts = 800;
do {
sleep 1;
$attempts--;
} until ((() = $log_file->slurp() =~ m/$re/g) > 6 || $attempts <= 0);
-
kill_service($_) for ($unstable_ws_pid, $w2_pid);
dead_workers($schema);
my @matches = $log_file->slurp() =~ m/$re/g;
@@ -299,6 +300,28 @@ subtest 'Websocket server - close connection test' => sub {
"Connection was turned off by ws server correctly";
};
+
+subtest 'Worker logs correctly' => sub {
+ kill_service($wspid);
+ my $log_file = tempfile;
+ local $ENV{OPENQA_LOGFILE};
+ local $ENV{MOJO_LOG_LEVEL};
+ my $worker_pid = create_worker($k->key, $k->secret, "http://bogushost:999999", 1, $log_file);
+ my @re = qr/\[worker:debug\] Using dir .*? for host .*/,
+ qr/\[worker:info\] registering worker with .*/,
+ qr/\[worker:error\] unable to connect to host .* retry in /,
+ qr/\[worker:debug\] ## adding timer register_worker-.*/;
+ sleep(5);
+ my $i = 0;
+ for my $re (@re) {
+ my @matches = $log_file->slurp() =~ m/$re/gm;
+ ok(1 == @matches, "Worker logs correctly @{[++$i]}");
+
+ }
+
+ kill_service $worker_pid;
+};
+
# This test destroys almost everything.
subtest 'Simulation of heavy failures' => sub {
my $allocated;
@@ -465,3 +488,4 @@ EOC
done_testing;
+
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/25-serverstartup.t b/t/25-serverstartup.t
index e286562b0a3..c1091383cb5 100644
--- a/t/25-serverstartup.t
+++ b/t/25-serverstartup.t
@@ -31,7 +31,7 @@ use strict;
use warnings;
use FindBin;
use lib "$FindBin::Bin/lib";
-use OpenQA::ServerStartup;
+use OpenQA::Setup;
use OpenQA::Utils;
use Test::More;
use Mojolicious;
@@ -41,7 +41,7 @@ subtest 'Setup logging to file' => sub {
local $ENV{OPENQA_LOGFILE} = undef;
my $tempfile = tempfile;
my $app = Mojolicious->new(config => {logging => {file => $tempfile}});
- OpenQA::ServerStartup::setup_logging($app);
+ OpenQA::Setup::setup_log($app);
$app->attr('log_name', sub { return "test"; });
my $log = $app->log;
@@ -57,14 +57,15 @@ subtest 'Setup logging to file' => sub {
like $content, qr/\[.*\] \[test:info\] Works too/, 'right info message';
};
-subtest 'Setup logging to STDERR' => sub {
+subtest 'Setup logging to STDOUT' => sub {
local $ENV{OPENQA_LOGFILE} = undef;
my $buffer = '';
my $app = Mojolicious->new();
- OpenQA::ServerStartup::setup_logging($app);
+ OpenQA::Setup::setup_log($app);
+ $app->attr('log_name', sub { return "test"; });
{
open my $handle, '>', \$buffer;
- local *STDERR = $handle;
+ local *STDOUT = $handle;
my $log = $app->log;
$log->error('Just works');
$log->fatal('Fatal error');
@@ -80,7 +81,7 @@ subtest 'Setup logging to STDERR' => sub {
subtest 'Setup logging to file (ENV)' => sub {
local $ENV{OPENQA_LOGFILE} = tempfile;
my $app = Mojolicious->new(config => {logging => {file => "/tmp/ignored_foo_bar"}});
- OpenQA::ServerStartup::setup_logging($app);
+ OpenQA::Setup::setup_log($app);
$app->attr('log_name', sub { return "test"; });
my $log = $app->log;
@@ -97,7 +98,7 @@ subtest 'Setup logging to file (ENV)' => sub {
ok !-e "/tmp/ignored_foo_bar";
$app = Mojolicious->new();
- OpenQA::ServerStartup::setup_logging($app);
+ OpenQA::Setup::setup_log($app);
$app->attr('log_name', sub { return "test"; });
$log = $app->log;
@@ -152,7 +153,7 @@ subtest 'Update configuration from Plugin requirements' => sub {
# inline packages declaration needs to appear as "loaded"
$INC{"OpenQA/FakePlugin/Fuzz.pm"} = undef;
$INC{"OpenQA/FakePlugin/Fuzzer.pm"} = undef;
- OpenQA::ServerStartup::update_config($config, "OpenQA::FakePlugin");
+ OpenQA::Setup::update_config($config, "OpenQA::FakePlugin");
ok exists($config->{auth}->{method}), "Config option exists for OpenQA::FakePlugin::Foo";
ok exists($config->{bar}->{foo}), "Config option exists for OpenQA::FakePlugin::FooBar";
@@ -171,7 +172,7 @@ subtest 'Update configuration from Plugin requirements' => sub {
push @{$app->plugins->namespaces}, "OpenQA::FakePlugin";
$app->config->{ini_config} = $config->{ini_config};
$app->plugin("FooFoo");
- OpenQA::ServerStartup::update_config($app->config, "OpenQA::FakePlugin");
+ OpenQA::Setup::update_config($app->config, "OpenQA::FakePlugin");
is $app->config->{foofoo}->{is_there}, "wohoo", "Right config option for OpenQA::FakePlugin::Foofoo";
};
done_testing();
diff --git a/t/28-logging.t b/t/28-logging.t
index 978502baa8d..6cab94b0e4d 100644
--- a/t/28-logging.t
+++ b/t/28-logging.t
@@ -20,17 +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::FakeApp;
+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 $re = 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};
-
+ 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
@@ -41,7 +42,7 @@ subtest 'Logging to stdout' => sub {
open STDOUT, '>', \$output;
### Testing code here ###
- my $app = OpenQA::FakeApp->new(
+ my $app = OpenQA::Setup->new(
mode => 'production',
log_name => 'worker',
instance => 1,
@@ -50,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');
@@ -59,9 +60,7 @@ subtest 'Logging to stdout' => sub {
# Close the capture (current stdout) and restore STDOUT (by dupping the old STDOUT);
close STDOUT;
open(STDOUT, '>&', $oldSTDOUT) or die "Can't dup \$oldSTDOUT: $!";
-
- # Tests
- my @matches = ($output =~ m/$re/gm);
+ my @matches = ($output =~ m/$reStdOut/gm);
ok(@matches / 2 == 3, 'Worker log matches');
for (my $i = 0; $i < @matches; $i += 2) {
ok($matches[$i] eq $matches[$i + 1], "OK $matches[$i]");
@@ -69,10 +68,11 @@ subtest 'Logging to stdout' => sub {
};
subtest 'Logging to file' => sub {
+ delete $ENV{OPENQA_LOGFILE};
$ENV{OPENQA_WORKER_LOGDIR} = tempdir;
make_path $ENV{OPENQA_WORKER_LOGDIR};
- my $app = OpenQA::FakeApp->new(
+ my $app = OpenQA::Setup->new(
mode => 'production',
log_name => 'worker',
instance => 1,
@@ -80,15 +80,13 @@ subtest 'Logging to file' => sub {
level => 'debug'
);
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');
# Tests
- my @matches = (Mojo::File->new($output_logfile)->slurp =~ m/$re/gm);
+ my @matches = (Mojo::File->new($output_logfile)->slurp =~ m/$reFile/gm);
ok(@matches / 2 == 3, 'Worker log matches');
for (my $i = 0; $i < @matches; $i += 2) {
ok($matches[$i] eq $matches[$i + 1], "OK $matches[$i]");
@@ -100,6 +98,7 @@ subtest 'Logging to file' => sub {
};
subtest 'log fatal to stderr' => sub {
+ delete $ENV{OPENQA_LOGFILE};
delete $ENV{OPENQA_WORKER_LOGDIR};
# Capture STDERR:
# 1- dups the current STDERR to $oldSTDERR. This is used to restore the STDERR later
@@ -111,7 +110,7 @@ subtest 'log fatal to stderr' => sub {
open STDERR, '>', \$output;
### Testing code here ###
- my $app = OpenQA::FakeApp->new(
+ my $app = OpenQA::Setup->new(
mode => 'production',
log_name => 'worker',
instance => 1,
@@ -136,40 +135,130 @@ subtest 'log fatal to stderr' => sub {
subtest 'Checking log level' => sub {
$ENV{OPENQA_WORKER_LOGDIR} = tempdir;
delete $ENV{MOJO_LOG_LEVEL}; # The Makefile is overriding this variable
+ delete $ENV{OPENQA_LOGFILE};
make_path $ENV{OPENQA_WORKER_LOGDIR};
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 $app = OpenQA::FakeApp->new(
+ 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();
- $OpenQA::Utils::app = $app;
+ # $OpenQA::Utils::app = $app;
log_debug('debug message');
log_info('info message');
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/$re/gm);
- ok(keys(%matches) == $counter--, "Worker log level $_ entry");
+ my %matches = map { $_ => 1 } (Mojo::File->new($output_logfile)->slurp =~ m/$reFile/gm);
+ 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};
+ delete $ENV{OPENQA_WORKER_LOGDIR};
+};
+
+subtest 'Logging to right place' => sub {
+ delete $ENV{OPENQA_LOGFILE};
+ $ENV{OPENQA_WORKER_LOGDIR} = tempdir;
+ make_path $ENV{OPENQA_WORKER_LOGDIR};
+
+ my $app = OpenQA::Setup->new(
+ mode => 'production',
+ log_name => 'worker',
+ instance => 1,
+ log_dir => $ENV{OPENQA_WORKER_LOGDIR},
+ level => 'debug'
+ );
+ my $output_logfile = catfile($ENV{OPENQA_WORKER_LOGDIR}, hostname() . '-1.log');
+ $app->setup_log();
+ log_debug('debug message');
+ log_error('error message');
+ log_info('info message');
+ ok(-f $output_logfile, 'Log file defined in logdir');
+
+ local $ENV{OPENQA_LOGFILE} = 'test_log_file.log';
+ $app = OpenQA::Setup->new(
+ mode => 'production',
+ log_name => 'worker',
+ instance => 1,
+ log_dir => $ENV{OPENQA_WORKER_LOGDIR},
+ level => 'debug'
+ );
+ $app->setup_log();
+ log_debug('debug message');
+ log_error('error message');
+ log_info('info message');
+ ok(
+ -f catfile($ENV{OPENQA_WORKER_LOGDIR}, $ENV{OPENQA_LOGFILE}),
+ 'Log file created defined in logdir and environment'
+ );
+
+
+ local $ENV{OPENQA_LOGFILE} = catfile($ENV{OPENQA_WORKER_LOGDIR}, 'another_test_log_file.log');
+ $app = OpenQA::Setup->new(
+ mode => 'production',
+ log_name => 'worker',
+ instance => 1,
+ level => 'debug'
+ );
+ $app->setup_log();
+ log_debug('debug message');
+ log_error('error message');
+ log_info('info message');
+ ok(-f $ENV{OPENQA_LOGFILE}, 'Log file created defined in environment');
# clear the system
remove_tree $ENV{OPENQA_WORKER_LOGDIR};
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/config.t b/t/config.t
index b371db7f733..4f2e5f26ba6 100644
--- a/t/config.t
+++ b/t/config.t
@@ -23,14 +23,14 @@ use lib "$FindBin::Bin/lib";
use Test::More;
use Test::Warnings;
use Mojolicious;
-use OpenQA::ServerStartup;
+use OpenQA::Setup;
subtest 'Test configuration default modes' => sub {
local $ENV{OPENQA_CONFIG} = undef;
my $app = Mojolicious->new();
$app->mode("test");
- OpenQA::ServerStartup::read_config($app);
+ OpenQA::Setup::read_config($app);
my $config = $app->config;
is(length($config->{_openid_secret}), 16, "config has openid_secret");
my $test_config = {
@@ -76,7 +76,7 @@ subtest 'Test configuration default modes' => sub {
# Test configuration generation with "development" mode
$app = Mojolicious->new();
$app->mode("development");
- OpenQA::ServerStartup::read_config($app);
+ OpenQA::Setup::read_config($app);
$config = $app->config;
$test_config->{_openid_secret} = $config->{_openid_secret};
is_deeply $config, $test_config, 'right "development" configuration';
@@ -84,7 +84,7 @@ subtest 'Test configuration default modes' => sub {
# Test configuration generation with an unknown mode (should fallback to default)
$app = Mojolicious->new();
$app->mode("foo_bar");
- OpenQA::ServerStartup::read_config($app);
+ OpenQA::Setup::read_config($app);
$config = $app->config;
$test_config->{_openid_secret} = $config->{_openid_secret};
$test_config->{auth}->{method} = "OpenID";
@@ -95,7 +95,7 @@ subtest 'Test configuration default modes' => sub {
# Test configuration generation with an unknown mode (should fallback to default)
$app = Mojolicious->new();
$app->mode("foo_bar");
- OpenQA::ServerStartup::read_config($app);
+ OpenQA::Setup::read_config($app);
$config = $app->config;
$test_config->{_openid_secret} = $config->{_openid_secret};
$test_config->{auth}->{method} = "OpenID";
@@ -118,7 +118,7 @@ subtest 'Test configuration override from file' => sub {
"blacklist = job_grab job_done\n"
);
$t_dir->child("openqa.ini")->spurt(@data);
- OpenQA::ServerStartup::read_config($app);
+ OpenQA::Setup::read_config($app);
ok -e $t_dir->child("openqa.ini");
ok($app->config->{global}->{suse_mirror} eq 'http://blah/', 'suse mirror');
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');