From 016409eca5e1367d2aad148595f073c0d68ddb18 Mon Sep 17 00:00:00 2001 From: Stephan Kulow Date: Mon, 12 Sep 2016 11:22:20 +0200 Subject: [PATCH] Split Logging support out of WebAPI and use it for webapi and scheduler --- lib/OpenQA/IPC.pm | 6 +- lib/OpenQA/Scheduler.pm | 22 +++++- lib/OpenQA/Scheduler/FakeApp.pm | 55 ++++++++++++++ lib/OpenQA/Schema.pm | 2 +- lib/OpenQA/ServerStartup.pm | 128 ++++++++++++++++++++++++++++++++ lib/OpenQA/Utils.pm | 2 - lib/OpenQA/WebAPI.pm | 108 ++------------------------- lib/OpenQA/WebSockets/Server.pm | 26 +++---- lib/db_profiler.pm | 12 +-- 9 files changed, 232 insertions(+), 129 deletions(-) create mode 100644 lib/OpenQA/Scheduler/FakeApp.pm create mode 100644 lib/OpenQA/ServerStartup.pm diff --git a/lib/OpenQA/IPC.pm b/lib/OpenQA/IPC.pm index fefc4f597a83..397ebba44bac 100644 --- a/lib/OpenQA/IPC.pm +++ b/lib/OpenQA/IPC.pm @@ -28,6 +28,7 @@ use Try::Tiny; use Carp; use Scalar::Util qw/weaken/; +use OpenQA::Utils qw/log_debug/; my $openqa_prefix = 'org.opensuse.openqa'; my %services = ( @@ -208,7 +209,10 @@ sub _dispatch { confess "error getting ipc service: $_"; }; my $object = $service->get_object('/' . $services{$target}, join('.', $openqa_prefix, $services{$target})); - return $object->$command(@data); + log_debug("dispatching IPC $command to $target: " . pp(\@data)); + my $ret = $object->$command(@data); + log_debug("IPC retrieved " . pp($ret)); + return $ret; } ## Helpers diff --git a/lib/OpenQA/Scheduler.pm b/lib/OpenQA/Scheduler.pm index 3d0bf92c2fb9..9c17cee342d5 100644 --- a/lib/OpenQA/Scheduler.pm +++ b/lib/OpenQA/Scheduler.pm @@ -1,4 +1,4 @@ -# Copyright (C) 2015 SUSE Linux GmbH +# Copyright (C) 2015-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 @@ -23,11 +23,31 @@ use Net::DBus::Reactor; use Data::Dump qw/pp/; use OpenQA::IPC; +use OpenQA::Scheduler::FakeApp; use OpenQA::Scheduler::Scheduler qw//; use OpenQA::Scheduler::Locks qw//; +use OpenQA::Utils qw/log_debug/; +use OpenQA::ServerStartup; +# monkey patching for debugging IPC +sub _is_method_allowed { + my ($self, $method) = @_; + + my $ret = $self->SUPER::_is_method_allowed($method); + if ($ret) { + log_debug "scheduler IPC calling $method"; + } + return $ret; +} + +our $fakeapp; sub run { + $fakeapp = OpenQA::Scheduler::FakeApp->new; + OpenQA::ServerStartup::read_config($fakeapp); + OpenQA::ServerStartup::setup_logging($fakeapp); + OpenQA::Scheduler->new(); + log_debug("Scheduler started"); Net::DBus::Reactor->main->run; } diff --git a/lib/OpenQA/Scheduler/FakeApp.pm b/lib/OpenQA/Scheduler/FakeApp.pm new file mode 100644 index 000000000000..200d867b60c9 --- /dev/null +++ b/lib/OpenQA/Scheduler/FakeApp.pm @@ -0,0 +1,55 @@ +# 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::Scheduler::FakeApp; +use Mojo::Log; +use strict; +use warnings; + +# implementing the interface of Mojolicious we need to get the rest doing debug +sub new { + my ($class) = @_; + my $self = bless {}, $class; + $self->{config} = {}; + $self->{log} = Mojo::Log->new; + return $self; +} + +sub mode { + my ($self) = @_; + return 'production'; +} + +sub config { + my ($self) = @_; + return $self->{config}; +} + +sub log { + my ($self) = @_; + return $self->{log}; +} + +sub schema { + my ($self) = @_; + return OpenQA::Schema::connect_db(); +} + +sub log_name { + my ($self) = @_; + return 'scheduler'; +} + +1; diff --git a/lib/OpenQA/Schema.pm b/lib/OpenQA/Schema.pm index 141968c8b9ad..5a7a603f67ac 100644 --- a/lib/OpenQA/Schema.pm +++ b/lib/OpenQA/Schema.pm @@ -37,9 +37,9 @@ sub _get_schema { } sub connect_db { - my $mode = shift || $ENV{OPENQA_DATABASE} || 'production'; my $schema = _get_schema; unless ($$schema) { + my $mode = shift || $ENV{OPENQA_DATABASE} || 'production'; my %ini; my $cfgpath = $ENV{OPENQA_CONFIG} || "$Bin/../etc/openqa"; my $database_file = $cfgpath . '/database.ini'; diff --git a/lib/OpenQA/ServerStartup.pm b/lib/OpenQA/ServerStartup.pm new file mode 100644 index 000000000000..434b4e81a918 --- /dev/null +++ b/lib/OpenQA/ServerStartup.pm @@ -0,0 +1,128 @@ +# Copyright (C) 2015-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 . + +# This package contains shared functions between WebAPI and WebSockets +package OpenQA::ServerStartup; + +use strict; +use warnings; +use Config::IniFiles; +use db_profiler; +use db_helpers; +use OpenQA::Utils; + +sub read_config { + my $app = shift; + + my %defaults = ( + global => { + appname => 'openQA', + base_url => undef, + branding => 'openSUSE', + allowed_hosts => undef, + download_domains => undef, + suse_mirror => undef, + scm => undef, + hsts => 365, + audit_enabled => 1, + plugins => undef, + hide_asset_types => 'repo', + }, + auth => { + method => 'OpenID', + }, + 'scm git' => { + do_push => 'no', + }, + logging => { + level => undef, + file => undef, + sql_debug => undef, + }, + openid => { + provider => 'https://www.opensuse.org/openid/user/', + httpsonly => 1, + }, + hypnotoad => { + listen => ['http://localhost:9526/'], + proxy => 1, + }, + audit => { + blacklist => '', + }, + ); + + # in development mode we use fake auth and log to stderr + my %mode_defaults = ( + development => { + auth => { + method => 'Fake', + }, + logging => { + file => undef, + level => 'debug', + }, + }, + test => { + auth => { + method => 'Fake', + }, + logging => { + file => undef, + level => 'debug', + }, + }); + + # Mojo's built in config plugins suck. JSON for example does not + # support comments + my $cfgpath = $ENV{OPENQA_CONFIG} || $app->home . '/etc/openqa'; + my $cfg = Config::IniFiles->new(-file => $cfgpath . '/openqa.ini') || undef; + + for my $section (sort keys %defaults) { + for my $k (sort keys %{$defaults{$section}}) { + my $v = $cfg && $cfg->val($section, $k); + $v //= exists $mode_defaults{$app->mode}{$section}->{$k} ? $mode_defaults{$app->mode}{$section}->{$k} : $defaults{$section}->{$k}; + $app->config->{$section}->{$k} = $v if defined $v; + } + } + $app->config->{_openid_secret} = db_helpers::rndstr(16); +} + +sub _log_format { + my ($app, $time, $level, @lines) = @_; + return '[' . localtime($time) . "] [" . $app->log_name . ":$level] " . join "\n", @lines, ''; +} + +sub setup_logging { + my ($app) = @_; + + my $config = $app->config; + my $logfile = $ENV{OPENQA_LOGFILE} || $config->{logging}->{file}; + $app->log->path($logfile); + $app->log->format(sub { _log_format($app, @_); }); + + if ($logfile && $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; +} + +1; diff --git a/lib/OpenQA/Utils.pm b/lib/OpenQA/Utils.pm index 4d2fd327b1f6..a78dd9eb07e5 100644 --- a/lib/OpenQA/Utils.pm +++ b/lib/OpenQA/Utils.pm @@ -152,8 +152,6 @@ sub file_content($;$) { } # logging helpers -# Withing Mojo openQA $app is defined and Mojo::Log is used -# Scheduler prints to stdout&stderr -> journal sub log_debug { my ($msg) = @_; if ($app && $app->log) { diff --git a/lib/OpenQA/WebAPI.pm b/lib/OpenQA/WebAPI.pm index deb75b51691d..58cec771dba5 100644 --- a/lib/OpenQA/WebAPI.pm +++ b/lib/OpenQA/WebAPI.pm @@ -20,95 +20,15 @@ use Mojo::Base 'Mojolicious'; use OpenQA::Schema; use OpenQA::WebAPI::Plugin::Helpers; use OpenQA::IPC; -use OpenQA::Worker::Common qw/ASSET_DIR/; use OpenQA::Utils qw/log_warning/; +use OpenQA::ServerStartup; use Mojo::IOLoop; use Mojolicious::Commands; use DateTime; use Cwd qw/abs_path/; use File::Path qw/make_path/; - -use Config::IniFiles; -use db_profiler; -use db_helpers; - -sub _read_config { - my $self = shift; - - my %defaults = ( - global => { - appname => 'openQA', - base_url => undef, - branding => 'openSUSE', - allowed_hosts => undef, - download_domains => undef, - suse_mirror => undef, - scm => undef, - hsts => 365, - audit_enabled => 1, - plugins => undef, - hide_asset_types => 'repo', - }, - auth => { - method => 'OpenID', - }, - 'scm git' => { - do_push => 'no', - }, - logging => { - level => undef, - file => undef, - sql_debug => undef, - }, - openid => { - provider => 'https://www.opensuse.org/openid/user/', - httpsonly => 1, - }, - hypnotoad => { - listen => ['http://localhost:9526/'], - proxy => 1, - }, - audit => { - blacklist => '', - }, - ); - - # in development mode we use fake auth and log to stderr - my %mode_defaults = ( - development => { - auth => { - method => 'Fake', - }, - logging => { - file => undef, - level => 'debug', - }, - }, - test => { - auth => { - method => 'Fake', - }, - logging => { - file => undef, - level => 'debug', - }, - }); - - # Mojo's built in config plugins suck. JSON for example does not - # support comments - my $cfgpath = $ENV{OPENQA_CONFIG} || $self->app->home . '/etc/openqa'; - my $cfg = Config::IniFiles->new(-file => $cfgpath . '/openqa.ini') || undef; - - for my $section (sort keys %defaults) { - for my $k (sort keys %{$defaults{$section}}) { - my $v = $cfg && $cfg->val($section, $k); - $v //= exists $mode_defaults{$self->mode}{$section}->{$k} ? $mode_defaults{$self->mode}{$section}->{$k} : $defaults{$section}->{$k}; - $self->app->config->{$section}->{$k} = $v if defined $v; - } - } - $self->app->config->{_openid_secret} = db_helpers::rndstr(16); -} +use OpenQA::Worker::Common qw/ASSET_DIR/; # reinit pseudo random number generator in every child to avoid # starting off with the same state. @@ -142,32 +62,20 @@ has secrets => sub { return $ret; }; -sub _log_format { - my ($time, $level, @lines) = @_; - return '[' . localtime($time) . "] [$$:$level] " . join "\n", @lines, ''; -} +has log_name => sub { + return $$; +}; # This method will run once at server start sub startup { my $self = shift; - $self->_read_config; + OpenQA::ServerStartup::read_config($self); # Set some application defaults $self->defaults(appname => $self->app->config->{global}->{appname}); - my $logfile = $ENV{OPENQA_LOGFILE} || $self->config->{logging}->{file}; - $self->log->path($logfile); - $self->log->format(\&_log_format); - - if ($logfile && $self->config->{logging}->{level}) { - $self->log->level($self->config->{logging}->{level}); - } - 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, $self->schema); - } + OpenQA::ServerStartup::setup_logging($self); unless ($ENV{MOJO_TMPDIR}) { $ENV{MOJO_TMPDIR} = ASSET_DIR . '/tmp'; @@ -223,8 +131,6 @@ sub startup { } }); - $OpenQA::Utils::app = $self; - # load auth module my $auth_method = $self->config->{auth}->{method}; my $auth_module = "OpenQA::WebAPI::Auth::$auth_method"; diff --git a/lib/OpenQA/WebSockets/Server.pm b/lib/OpenQA/WebSockets/Server.pm index 3e3e190a567b..408bf9e9d146 100644 --- a/lib/OpenQA/WebSockets/Server.pm +++ b/lib/OpenQA/WebSockets/Server.pm @@ -20,6 +20,7 @@ use Mojo::Util 'hmac_sha1_sum'; use OpenQA::IPC; use OpenQA::Utils qw/log_debug log_warning/; use OpenQA::Schema; +use OpenQA::ServerStartup; use db_profiler; @@ -121,14 +122,13 @@ sub ws_create { sub ws_is_worker_connected { my ($workerid) = @_; - defined $worker_sockets->{$workerid} ? 1 : 0; + return (defined $worker_sockets->{$workerid} ? 1 : 0); } # internal helpers sub _validate_workerid { my ($workerid) = @_; - my $schema = OpenQA::Schema::connect_db; - my $worker = $schema->resultset("Workers")->find($workerid); + return app->schema->resultset("Workers")->find($workerid); } sub _get_workerid { @@ -252,20 +252,12 @@ sub _workers_checker { # Mojolicious startup sub setup { - - # TODO: read openQA config - # $self->defaults(appname => 'openQA::WebSockets'); - # - # $self->_read_config; - # my $logfile = $ENV{OPENQA_WS_LOGFILE} || $self->config->{logging}->{file}; - # $self->log->path($logfile); - # - # if ($logfile && $self->config->{logging}->{level}) { - # $self->log->level($self->config->{logging}->{level}); - # } - - # db_profiler::enable_sql_debugging(app, OpenQA::Schema::connect_db); - # app->log->level('debug'); + app->helper(schema => sub { return OpenQA::Schema::connect_db; }); + # not really meaningful for websockets, but required for mode defaults + app->helper(mode => sub { return 'production' }); + app->helper(log_name => sub { return 'websockets' }); + OpenQA::ServerStartup::read_config(app); + OpenQA::ServerStartup::setup_logging(app); # use port one higher than WebAPI my $port = 9527; diff --git a/lib/db_profiler.pm b/lib/db_profiler.pm index a046221edd9d..df1f544aca87 100644 --- a/lib/db_profiler.pm +++ b/lib/db_profiler.pm @@ -30,25 +30,25 @@ sub query_end { sub enable_sql_debugging { - my ($app, $schema) = @_; - my $storage = $schema->storage; + my ($app) = @_; + my $storage = $app->schema->storage; $storage->debugobj(new db_profiler()); - $storage->debugfh(MojoDebugHandle->new($app)); + $storage->debugfh(MojoDebugHandle->new($app->log)); $storage->debug(1); } package MojoDebugHandle; sub new { - my ($class, $app) = @_; + my ($class, $log) = @_; - return bless {app => $app}, $class; + return bless {log => $log}, $class; } sub print { my ($self, $line) = @_; chop $line; - $self->{app}->app->log->debug($line); + $self->{log}->debug($line); }