action #57107

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

Added by okurz 5 months ago. Updated 4 months ago.

Status:ResolvedStart date:19/09/2019
Priority:LowDue date:
Assignee:tinita% Done:

100%

Category:Concrete Bugs
Target version:Current Sprint
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 5 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 5 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 5 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 5 months ago

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

#6 Updated by mkittler 5 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 4 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 4 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 4 months ago

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

#12 Updated by okurz 4 months ago

  • Status changed from Feedback to Resolved

verified in production, thx

Also available in: Atom PDF