Project

General

Profile

Actions
Copy link

action #53435

open

[logwarn] o3: DBI Exception: number of parameters must be between 0 and 65535 in lib/OpenQA/WebAPI/Controller/API/V1/Job.pm line 133

Added by okurz over 5 years ago. Updated 11 months ago.

Status:
New
Priority:
Normal
Assignee:
-
Category:
Regressions/Crashes
Target version:
QA - future
Start date:
2019-06-21
Due date:
% Done:

0%

Estimated time:

Description

Observation

This nearly killed my email client, from o3 monitoring in /var/log/openqa:

[2019-06-21T09:25:50.0548 UTC] [error] DBIx::Class::Storage::DBI::_dbh_execute(): DBI Exception: DBD::Pg::st execute failed: number of parameters must be between 0 and 65535 [for Statement "SELECT me.job_id, me.asset_id, me.created_by, me.t_created, me.t_updated, asset.id, asset.type, asset.name, asset.size, asset.checksum, asset.last_use_job_id, asset.fixed, asset.t_created, asset.t_updated FROM jobs_assets me  JOIN assets asset ON asset.id = me.asset_id WHERE ( job_id IN ( ?, … ) )" with ParamValues: 1='934057', 2='775775', 3='774972', 4='852279', 5='937661', 6='957555', 7='924633', 8='869768', 9='889133', 10='865729',… 80516='740865'] at /usr/share/openqa/script/../lib/OpenQA/WebAPI/Controller/API/V1/Job.pm line 133

Problem

Looks like one of the reasons why people preferred to ditch sqlite which couldn't handle more than 5k jobs, postgres's limit seems to be at 216 ;)

https://github.com/os-autoinst/openQA/blob/master/lib/OpenQA/WebAPI/Controller/API/V1/Job.pm#L133 is within the method "list" trying to iterative over the assets of jobs:

132:    my $jas = $schema->resultset('JobsAssets')->search({job_id => {in => [keys %jobs]}}, {prefetch => ['asset']});
133:    while (my $ja = $jas->next) {
Actions
Copy link
 #2

Updated by okurz over 5 years ago

  • Priority changed from Normal to High

these messages unfortunately pass the logwarn filter and clog up the o3-admins mailing list input channel because they are so big. Trying to display these emails with my email client kmail is even a challenge. I would appreciate if we can look into this soon.

Actions
Copy link
 #3

Updated by okurz over 5 years ago

[2019-07-10T10:58:26.0989 UTC] is the last timestamp I found.

But actually it does not happen that often:

# grep 'must be between' /var/log/openqa | grep 2019-0[67]- | cut -c -100
[2019-06-21T09:25:50.0548 UTC] [error] DBIx::Class::Storage::DBI::_dbh_execute(): DBI Exception: DBD
[2019-06-25T16:35:55.0844 UTC] [error] DBIx::Class::Storage::DBI::_dbh_execute(): DBI Exception: DBD
[2019-06-25T16:36:18.0171 UTC] [error] DBIx::Class::Storage::DBI::_dbh_execute(): DBI Exception: DBD
[2019-06-25T16:36:34.0783 UTC] [error] DBIx::Class::Storage::DBI::_dbh_execute(): DBI Exception: DBD
[2019-07-10T10:57:13.0747 UTC] [error] DBIx::Class::Storage::DBI::_dbh_execute(): DBI Exception: DBD
[2019-07-10T10:58:26.0989 UTC] [error] DBIx::Class::Storage::DBI::_dbh_execute(): DBI Exception: DBD

I wonder if that is an external request triggering it or something from openQA or internal to o3 itself. With this low number of occurences I don't think we can find something easily in apache access logs.

Actions
Copy link
 #4

Updated by okurz over 5 years ago

  • Priority changed from High to Normal

https://github.com/os-autoinst/openqa-logwarn/pull/12 created to at least cut the overly long lines in reporting.

Actions
Copy link
 #5

Updated by mkittler about 5 years ago

  • Assignee set to mkittler

One can reproduce this locally with an o3 dump using script/client --host localhost:9526 jobs. We could split the query but returning that much data (the JSON object contains the settings for each job!) makes no sense. So I would simply limit it.

Actions
Copy link
 #6

Updated by mkittler about 5 years ago

  • Status changed from New to In Progress
  • Target version set to Current Sprint
Actions
Copy link
 #7

Updated by mkittler about 5 years ago

  • Status changed from In Progress to Resolved

PR has been merged

Actions
Copy link
 #8

Updated by mkittler about 5 years ago

  • Target version changed from Current Sprint to Done
Actions
Copy link
 #9

Updated by tinita 11 months ago

  • Status changed from Resolved to Workable
  • Target version deleted (Done)

We are still ignoring this error message and reference this tickets:
https://github.com/os-autoinst/openqa-logwarn/blob/master/logwarn_openqa#L67C8-L67C50
I would say a ticket shouldn't be resolved when it's still referenced and errors actively ignored.

Actions
Copy link
 #10

Updated by tinita 11 months ago

  • Status changed from Workable to New
Actions
Copy link
 #11

Updated by okurz 11 months ago

  • Assignee deleted (mkittler)
  • Target version set to future
Actions
Copy link

Also available in: Atom PDF