[Koha-bugs] [Bug 34070] New: background_jobs_worker.pl fills logs when not connecting
bugzilla-daemon at bugs.koha-community.org
bugzilla-daemon at bugs.koha-community.org
Tue Jun 20 19:21:36 CEST 2023
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=34070
Bug ID: 34070
Summary: background_jobs_worker.pl fills logs when not
connecting
Change sponsored?: ---
Product: Koha
Version: 22.11
Hardware: All
OS: All
Status: NEW
Severity: major
Priority: P5 - low
Component: Architecture, internals, and plumbing
Assignee: koha-bugs at lists.koha-community.org
Reporter: magnus at libriotech.no
QA Contact: testopia at bugs.koha-community.org
I noticed my disk was filling up, because worker-output.log was getting several
hundred of these per second:
[2023/06/20 18:21:24] [WARN] Frame not processed - malformed JSON string,
neither tag, array, object, number, string or atom, at character offset 0
(before "You must log in usin...") at
/usr/share/koha/bin/background_jobs_worker.pl line 116.
main::catch {...} /usr/share/koha/bin/background_jobs_worker.pl (119)
I think the problem is related to this code:
106 while (1) {
107 if ( $conn ) {
108 my $frame = $conn->receive_frame;
109 if ( !defined $frame ) {
110 # maybe log connection problems
111 next; # will reconnect automatically
112 }
113
114 my $args = try {
115 my $body = $frame->body;
116 decode_json($body); # TODO Should this be from_json? Check utf8
flag.
117 } catch {
118 Koha::Logger->get({ interface => 'worker' })->warn(sprintf
"Frame not processed - %s", $_);
119 return;
120 } finally {
121 $conn->ack( { frame => $frame } );
122 };
123
124 next unless $args;
125
126 # FIXME This means we need to have create the DB entry before
127 # It could work in a first step, but then we will want to handle
job that will be created from the message received
128 my $job = Koha::BackgroundJobs->find($args->{job_id});
There is a problem with the connection, but $conn is still defined, so this
code is run. When I Dump $conn after line 107 it looks like this:
$VAR1 = bless( {
'bufsize' => 8192,
'logger' => bless( {
'warn' => 1,
'error' => 1,
'fatal' => 1
}, 'Net::Stomp::StupidLogger' ),
'_framebuf_changed' => 1,
'port' => '61613',
'connect_delay' => 5,
'_pid' => ***,
'hostname' => 'localhost',
'reconnect_attempts' => 0,
'reconnect_on_fork' => 1,
'select' => bless( [
'�',
1,
undef,
undef,
undef,
undef,
undef,
undef,
undef,
bless( \*Symbol::GEN0, 'IO::Socket::IP' )
], 'IO::Select' ),
'socket' => $VAR1->{'select'}[9],
'initial_reconnect_attempts' => 1,
'_framebuf' => '',
'socket_options' => {},
'subscriptions' => {
'dest-/queue/koha_***-default' => {
'ack' => 'client',
'destination' => '/queue/koha_***-default',
'prefetch-count' => 1
}
}
}, 'Net::Stomp' );
If I dump the contents of $body after line 115, I get 'You must log in using
CONNECT first'. Not sure why that happens yet, but how we handle it seems to be
problematic. We fail to decode it, because it is not JSON. So the "catch" block
is run and logs the problem. But then I think the "return" kicks us back to the
start of the "while" and we end up logging the same error as fast as we can,
which seems to be pretty fast. And we never get to the "ack" on line 121.
The comment "will reconnect automatically" seems to be a little optimistic?
Moving the "return" from the end of the "catch" block, to the end of the
"finally" block slows things down, now the logging only happens about every
other second.
But there is also a problem because we are assigning the "output" from the
try/catch to $args. If we can decode_json the $body, that works as expected.
But if we execute the "catch" block, it looks like $args gets assigned the
result of Koha::Logger->get, which seems to be 1. So $args is defined on line
124 and we get to Koha::BackgroundJobs->find, but using "1" as a hashref there
does not work.
I think maybe something like this would work better:
my $args;
try {
my $body = $frame->body;
$args = decode_json($body); # TODO Should this be from_json? Check
utf8 flag.
} catch {
Koha::Logger->get({ interface => 'worker' })->warn(sprintf "Frame
not processed - %s", $_);
} finally {
$conn->ack( { frame => $frame } );
return;
};
Is the return needed? This is a little above my head, so other solutions are
most welcome. And if anyone can tell me why I get 'You must log in using
CONNECT first' I would be most grateful. :-)
--
You are receiving this mail because:
You are watching all bug changes.
You are the assignee for the bug.
More information about the Koha-bugs
mailing list