Skip to content

Commit 74cc45d

Browse files
committed
Avoid Transaction already destroyed being logged as error
This exception that is normally logged as error is not really due to an error condition but because the client has already closed the connection so and thus processing the request is aborted. This change replaces the default error handler of Mojolicious to avoid this exception being logged as error and turns it instead into a debug message which is hopefully easier to understand. Related ticket: https://progress.opensuse.org/issues/184486
1 parent ce019b3 commit 74cc45d

File tree

2 files changed

+22
-2
lines changed

2 files changed

+22
-2
lines changed

lib/OpenQA/WebAPI.pm

Lines changed: 13 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -7,11 +7,12 @@ use Mojo::Base 'Mojolicious', -signatures;
77
use OpenQA::Assets;
88
use OpenQA::Schema;
99
use OpenQA::WebAPI::Plugin::Helpers;
10-
use OpenQA::Log 'setup_log';
10+
use OpenQA::Log qw(setup_log log_debug log_error);
1111
use OpenQA::Utils qw(detect_current_version service_port);
1212
use OpenQA::Setup;
1313
use OpenQA::WebAPI::Description qw(get_pod_from_controllers set_api_desc);
1414
use Mojo::File 'path';
15+
use Mojo::IOLoop;
1516
use Mojo::Util 'trim';
1617
use Feature::Compat::Try;
1718

@@ -489,6 +490,11 @@ sub startup ($self) {
489490

490491
$self->plugin('OpenQA::WebAPI::Plugin::MemoryLimit');
491492

493+
# treat certain exceptions as non-errors
494+
my $reactor = Mojo::IOLoop->singleton->reactor;
495+
$reactor->unsubscribe('error'); # avoid default handling of always logging an error
496+
$reactor->on(error => \&_handle_exception);
497+
492498
# add method to be called before rendering
493499
$app->hook(
494500
before_render => sub ($c, $args) {
@@ -516,6 +522,12 @@ sub startup ($self) {
516522
}
517523
}
518524

525+
sub _handle_exception ($reactor, $err) {
526+
return log_debug 'Connection lost (e.g. closed by client), abort processing request'
527+
if $err =~ m/Transaction already destroyed/;
528+
return log_error $err;
529+
}
530+
519531
sub schema ($self) { OpenQA::Schema->singleton }
520532

521533
sub run () { __PACKAGE__->new->start }

t/25-serverstartup.t

Lines changed: 9 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -23,10 +23,11 @@ use OpenQA::Assets;
2323
use OpenQA::Log 'setup_log';
2424
use OpenQA::Setup;
2525
use OpenQA::Utils;
26+
use OpenQA::WebAPI;
2627
use Mojolicious;
2728
use Mojo::File qw(tempfile path);
2829
use Mojo::Home;
29-
use Test::Output qw(combined_from);
30+
use Test::Output qw(combined_from combined_like);
3031

3132
subtest 'Setup logging to file' => sub {
3233
local $ENV{OPENQA_LOGFILE} = undef;
@@ -71,6 +72,13 @@ subtest 'Setup logging to STDOUT' => sub {
7172
like $buffer, qr/\[info\] Works too\n/, 'right info message';
7273
};
7374

75+
subtest 'global exception handling' => sub {
76+
combined_like { OpenQA::WebAPI::_handle_exception(undef, 'foo') } qr/error.*foo/,
77+
'exceptions generally logged as errors';
78+
combined_like { OpenQA::WebAPI::_handle_exception(undef, 'Transaction already destroyed') }
79+
qr/debug.*abort processing/, 'destroyed transactions logged as debug message';
80+
};
81+
7482
subtest 'Setup logging to file (ENV)' => sub {
7583
local $ENV{OPENQA_LOGFILE} = tempfile;
7684
my $app = Mojolicious->new(config => {logging => {file => "/tmp/ignored_foo_bar"}});

0 commit comments

Comments
 (0)