Project

General

Profile

action #57107

Spammy log message in `journalctl -u openqa-webui` about `BEGIN WORK, COMMIT` without further helpful information

Added by okurz 10 months ago. Updated 8 months ago.

Status:
Resolved
Priority:
Low
Assignee:
Category:
Concrete Bugs
Target version:
Start date:
2019-09-19
Due date:
% Done:

100%

Estimated time:
Difficulty:
Duration:

Description

Observation

On osd journactl -u openqa-webui seems to be way more spammy now with not so helpful messages:

Sep 19 13:30:13 openqa openqa[13378]: Server available at http://127.0.0.1:9526
Sep 19 13:30:13 openqa openqa[13378]: Server available at http://[::1]:9526
Sep 19 13:30:14 openqa openqa[13378]: BEGIN WORK
Sep 19 13:30:14 openqa openqa[13378]: COMMIT
Sep 19 13:30:14 openqa openqa[13378]: BEGIN WORK
Sep 19 13:30:14 openqa openqa[13378]: COMMIT
Sep 19 13:30:14 openqa openqa[13378]: BEGIN WORK
Sep 19 13:30:14 openqa openqa[13378]: COMMIT

Is this pointing to a problem that should have more information about the source of problem? Or is it a less interesting message that we can get rid of.

History

#1 Updated by coolo 10 months ago

it's triggered by sql_debug - somehow some sql is printed not logged. That's why I normally put everything in the journal if I enable it

#3 Updated by okurz 10 months ago

did you also recently change the openQA configs on o3 but not osd to not save logs in /var/log/openqa anymore but only journal? Why different on osd then?

#4 Updated by mkittler 9 months ago

Likely OPENQA_SQL_DEBUG=1 was set. This would log the message when starting a transaction. Possibly the transaction only contained raw SQL statements (rather than DBIx calls). Those are only logged when DBI_TRACE=1 is set as well.

So this issue would be resolved by using the environment variables consistently. Maybe openQA should implicitly set DBI_TRACE=1 if OPENQA_SQL_DEBUG=1 was set?

#5 Updated by coolo 9 months ago

we don't use any environment variables. sql_debug is an option in openqa.ini

#6 Updated by mkittler 9 months ago

OPENQA_SQL_DEBUG just overrides sql_debug in openqa.ini.

So what to do with that ticket? sql_debug has been disabled on OSD again. Should OPENQA_SQL_DEBUG/sql_debug also imply DBI_TRACE for consistency?

#7 Updated by coolo 9 months ago

  • Priority changed from Normal to Low

To me the ticket is: Get the transaction details in the same log file as the rest of SQL_DEBUG. For some reason they end up on stdout while the rest of dbix is ending up in the log file.

#8 Updated by tinita 9 months ago

  • Status changed from New to In Progress
  • Assignee set to tinita
  • Target version changed from Ready to Current Sprint

We can just override the print method.

#10 Updated by tinita 9 months ago

  • Status changed from In Progress to Feedback
  • % Done changed from 0 to 100

#12 Updated by okurz 8 months ago

  • Status changed from Feedback to Resolved

verified in production, thx

Also available in: Atom PDF