OVIRT_ENGINE_DWH org.postgresql.util.PSQLException:ERROR: more than one row returned by a subquery used as an expression
2:06 p.m.
After many attempts and many uninstalls, (wiping of the ovirt_engine_history database,
removal of the associated database user, removal of all ovirt-engine-dwh folders and
configs in /etc, and so on...) and reinstalls, I can't figure out how to get Data
Warehouse to work properly. The dashboard isn't getting populated with data and this
error message constantly shows in Alerts and Events in the Web Administration console:
"ETL service sampling has encountered an error. Please consult the service log for
more details."
Also, the file /var/log/ovirt-engine-dwh/ovirt-engine-dwhd.log shows the following error
repeatedly:
2017-XX-XX
13:45:01|BFAPtJ|3TsCll|B5fdZD|OVIRT_ENGINE_DWH|SampleTimeKeepingJob|Default|6|Java
Exception|tRunJob_1|java.lang.RuntimeException:Child job running failed|1
Exception in component tJDBCInput_9
org.postgresql.util.PSQLException: ERROR: more than one row returned by a subquery used as
an expression
at
org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2157)
at
org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1886)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255)
at
org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:555)
at
org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:403)
at
org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:283)
at
ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync.tJDBCInput_9Process(ConfigurationSync.java:3727)
at
ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync$2.run(ConfigurationSync.java:60001)
2017-XX-XX 13:45:01|wqfyxb|3TsCll|76BFD3|OVIRT_ENGINE_DWH|ConfigurationSync|Default|6|Java
Exception|tJDBCInput_9|org.postgresql.util.PSQLException:ERROR: more than one row returned
by a subquery used as an expression|1
Exception in component tRunJob_1
java.lang.RuntimeException: Child job running failed
at
ovirt_engine_dwh.samplerunjobs_4_1.SampleRunJobs.tRunJob_1Process(SampleRunJobs.java:1198)
at
ovirt_engine_dwh.samplerunjobs_4_1.SampleRunJobs.tRunJob_4Process(SampleRunJobs.java:1000)
at
ovirt_engine_dwh.samplerunjobs_4_1.SampleRunJobs.tJDBCConnection_2Process(SampleRunJobs.java:767)
at
ovirt_engine_dwh.samplerunjobs_4_1.SampleRunJobs.tJDBCConnection_1Process(SampleRunJobs.java:642)
at
ovirt_engine_dwh.samplerunjobs_4_1.SampleRunJobs$2.run(SampleRunJobs.java:2683)
2017-XX-XX 13:45:01|76BFD3|3TsCll|FlSijV|OVIRT_ENGINE_DWH|SampleRunJobs|Default|6|Java
Exception|tRunJob_1|java.lang.RuntimeException:Child job running failed|1
Exception in component tRunJob_1
java.lang.RuntimeException: Child job running failed
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob.tRunJob_1Process(SampleTimeKeepingJob.java:6067)
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob.tJDBCInput_2Process(SampleTimeKeepingJob.java:5809)
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob.tJDBCConnection_1Process(SampleTimeKeepingJob.java:4444)
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob.tJDBCConnection_2Process(SampleTimeKeepingJob.java:4319)
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob.tRowGenerator_2Process(SampleTimeKeepingJob.java:4188)
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob.tJDBCInput_3Process(SampleTimeKeepingJob.java:3593)
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob.tJDBCInput_5Process(SampleTimeKeepingJob.java:2977)
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob.tJDBCInput_4Process(SampleTimeKeepingJob.java:2295)
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob.tJDBCConnection_3Process(SampleTimeKeepingJob.java:1649)
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob$2.run(SampleTimeKeepingJob.java:11363)
I just finished updating to oVirt 4.1.5 earlier today. My Internet searches have not
provided me with any further insight. Has anyone else experienced this issue? Has anyone
else resolved this issue? What should I be looking at to start debugging this issue (a
section of the database perhaps...)?
Thanks,
Charles
2:08 a.m.
On Wed, Aug 23, 2017 at 9:06 PM, Charles Gruener <cjg9411(a)rit.edu> wrote:
After many attempts and many uninstalls, (wiping of the
ovirt_engine_history database, removal of the associated database user, removal of all
ovirt-engine-dwh folders and configs in /etc, and so on...) and reinstalls, I can't
figure out how to get Data Warehouse to work properly. The dashboard isn't getting
populated with data and this error message constantly shows in Alerts and Events in the
Web Administration console:
"ETL service sampling has encountered an error. Please consult the service log for
more details."
Also, the file /var/log/ovirt-engine-dwh/ovirt-engine-dwhd.log shows the following error
repeatedly:
2017-XX-XX
13:45:01|BFAPtJ|3TsCll|B5fdZD|OVIRT_ENGINE_DWH|SampleTimeKeepingJob|Default|6|Java
Exception|tRunJob_1|java.lang.RuntimeException:Child job running failed|1
Exception in component tJDBCInput_9
org.postgresql.util.PSQLException: ERROR: more than one row returned by a subquery used
as an expression
at
org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2157)
at
org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1886)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255)
at
org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:555)
at
org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:403)
at
org.postgresql.jdbc2.AbstractJdbc2Statement.executeQuery(AbstractJdbc2Statement.java:283)
at
ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync.tJDBCInput_9Process(ConfigurationSync.java:3727)
This is the first line in the above stack trace that is from dwh (not
from postgresql libraries).
If you check the sources looking at this file around line 3727, you see:
String dbquery_tJDBCInput_9 =
"SELECT\n user_id,\n first_name,\n last_name,\n domain,\n
username,\n department,\n user_role_title,\n email,\n
external_id,\n active,\n create_date,\n update_date\nFROM
dwh_users_history_view";
globalMap.put("tJDBCInput_9_QUERY",
dbquery_tJDBCInput_9);
java.sql.ResultSet rs_tJDBCInput_9 = null;
try {
rs_tJDBCInput_9 = stmt_tJDBCInput_9
.executeQuery(dbquery_tJDBCInput_9);
So I guess the query selects stuff from dwh_users_history_view. This
view is defined in the engine sources (not dwh), if you search its
name you find it at packaging/dbscripts/create_dwh_views.sql:
CREATE OR REPLACE VIEW dwh_users_history_view AS
SELECT user_id,
name AS first_name,
surname AS last_name,
DOMAIN,
username,
department,
'' AS user_role_title,
email,
external_id,
TRUE AS active,
_create_date AS create_date,
_update_date AS update_date
FROM users
WHERE (
(
_create_date > (
SELECT var_datetime
FROM dwh_history_timekeeping
WHERE (var_name = 'lastSync')
)
)
OR (
_update_date > (
SELECT var_datetime
FROM dwh_history_timekeeping AS history_timekeeping_1
WHERE (var_name = 'lastSync')
)
)
);
So, as you see, it has subqueries selecting from
dwh_history_timekeeping, which is a table in the engine db used by dwh
to track various stuff about its operation.
at
ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync$2.run(ConfigurationSync.java:60001)
2017-XX-XX
13:45:01|wqfyxb|3TsCll|76BFD3|OVIRT_ENGINE_DWH|ConfigurationSync|Default|6|Java
Exception|tJDBCInput_9|org.postgresql.util.PSQLException:ERROR: more than one row returned
by a subquery used as an expression|1
Exception in component tRunJob_1
java.lang.RuntimeException: Child job running failed
at
ovirt_engine_dwh.samplerunjobs_4_1.SampleRunJobs.tRunJob_1Process(SampleRunJobs.java:1198)
at
ovirt_engine_dwh.samplerunjobs_4_1.SampleRunJobs.tRunJob_4Process(SampleRunJobs.java:1000)
at
ovirt_engine_dwh.samplerunjobs_4_1.SampleRunJobs.tJDBCConnection_2Process(SampleRunJobs.java:767)
at
ovirt_engine_dwh.samplerunjobs_4_1.SampleRunJobs.tJDBCConnection_1Process(SampleRunJobs.java:642)
at
ovirt_engine_dwh.samplerunjobs_4_1.SampleRunJobs$2.run(SampleRunJobs.java:2683)
2017-XX-XX 13:45:01|76BFD3|3TsCll|FlSijV|OVIRT_ENGINE_DWH|SampleRunJobs|Default|6|Java
Exception|tRunJob_1|java.lang.RuntimeException:Child job running failed|1
Exception in component tRunJob_1
java.lang.RuntimeException: Child job running failed
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob.tRunJob_1Process(SampleTimeKeepingJob.java:6067)
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob.tJDBCInput_2Process(SampleTimeKeepingJob.java:5809)
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob.tJDBCConnection_1Process(SampleTimeKeepingJob.java:4444)
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob.tJDBCConnection_2Process(SampleTimeKeepingJob.java:4319)
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob.tRowGenerator_2Process(SampleTimeKeepingJob.java:4188)
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob.tJDBCInput_3Process(SampleTimeKeepingJob.java:3593)
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob.tJDBCInput_5Process(SampleTimeKeepingJob.java:2977)
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob.tJDBCInput_4Process(SampleTimeKeepingJob.java:2295)
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob.tJDBCConnection_3Process(SampleTimeKeepingJob.java:1649)
at
ovirt_engine_dwh.sampletimekeepingjob_4_1.SampleTimeKeepingJob$2.run(SampleTimeKeepingJob.java:11363)
I just finished updating to oVirt 4.1.5 earlier today. My Internet searches have not
provided me with any further insight. Has anyone else experienced this issue? Has anyone
else resolved this issue? What should I be looking at to start debugging this issue (a
section of the database perhaps...)?
You can try looking at the dwh_history_timekeeping table in the engine
(not dwh) database:
su - postgres -c 'psql engine -c "select * from
dwh_history_timekeeping;"'
Most likely you'll find there more than one line with var_name 'lastSync'.
How this happened is quite interesting/useful to know, because it
should not normally happen, and is most likely a bug. If you can
reproduce this, please file a bug with relevant details. Thanks!
How to fix? If you do not need your engine, just remove everything and
try again.
If you do, you can try removing some of the duplicate lines. If they
are different, you'll have to use your own judgment to choose the
correct ones, or share the content and we can try to help.
Best,
Thanks,
Charles
_______________________________________________
Users mailing list
Users(a)ovirt.org
http://lists.ovirt.org/mailman/listinfo/users
--
Didi
3:47 p.m.
Thank you so much for the detailed response!
You can try looking at the dwh_history_timekeeping table in the
engine
(not dwh) database:
su - postgres -c 'psql engine -c "select * from
dwh_history_timekeeping;"'
Most likely you'll find there more than one line with var_name 'lastSync’.
And that I most certainly did. There were double of each var_name. I simply deleted one
of each of the pairs that made the most sense to delete, reran engine-setup and all
appears to be working now!
How this happened is quite interesting/useful to know, because it
should not normally happen, and is most likely a bug. If you can
reproduce this, please file a bug with relevant details. Thanks!
I’m pretty sure this was a self-inflicted issue as a while back when things broke, we
actually had two oVirt heads running but we didn’t catch it for a while. Basically, we
migrated from a VM running the head (on a separate VM solution) to a hardware solution.
Someone ended up turning the VM back on and it started wreaking havoc on our installation.
This was likely a leftover from that condition. If it happens to return, I’ll be sure to
file a bug.
One last question: Data for the Storage section of the Global Utilization part of the
dashboard is empty. We are using Ceph via Cinder for our storage. Is that the issue?
Side note: we are now being bitten by this bug -
https://bugzilla.redhat.com/show_bug.cgi?id=1465825
Thanks again for the assistance.
Charles
4:16 a.m.
On Fri, Aug 25, 2017 at 10:47 PM, Charles Gruener <cjg9411(a)rit.edu> wrote:
Thank you so much for the detailed response!
Glad it helped :-)
> You can try looking at the dwh_history_timekeeping table in the engine
> (not dwh) database:
>
> su - postgres -c 'psql engine -c "select * from
dwh_history_timekeeping;"'
>
> Most likely you'll find there more than one line with var_name 'lastSync’.
And that I most certainly did. There were double of each var_name. I simply deleted one
of each of the pairs that made the most sense to delete, reran engine-setup and all
appears to be working now!
> How this happened is quite interesting/useful to know, because it
> should not normally happen, and is most likely a bug. If you can
> reproduce this, please file a bug with relevant details. Thanks!
I’m pretty sure this was a self-inflicted issue as a while back when things broke, we
actually had two oVirt heads running but we didn’t catch it for a while. Basically, we
migrated from a VM running the head (on a separate VM solution) to a hardware solution.
How? Using engine-backup? Some kind of duplication/imaging?
Someone ended up turning the VM back on and it started wreaking
havoc on our installation.
Ouch.
This is one of my bad dreams re backup/restore/migration.
We try to emphasize in various guides that you must stop and disable
the engine service on the old machine. If you can think of anything
that could have further helped in your own situation/flow/case, do not
hesitate to ping us! Saying "This was obviously our own fault, the
software was just fine" is helpful only to some extent. That said, I
did not hear so far about exactly-same cases, although this does not
mean there aren't any.
This was likely a leftover from that condition.
Can you think how, exactly?
Can't tell exactly from your emails, but it seems you had engine+dwh
on the same machine.
Did you have DBs on a separate machine (which is not the default)? If
so, it makes sense.
The two machines' processes' both updated the same DBs.
But if you did use local DBs, and accessed them with host 'localhost'
(which is the default), the above should not have happened. Each
machine would then write to its own DBs.
This still quite bad - because you are then having two engines talking
to the same hosts - but in a different way.
Also: if I were you, I'd not keep trusting this system. If it works,
fine. It might break in the future - the above is definitely not part
of the design, not tested, not supported, etc. If at all possible,
perhaps consider reinstalling from scratch (not engine-backup
backup/restore). You can import the existing storage domains, if they
are not damaged as well. Can't even tell you how to test this. If the
individual VMs' disks seem ok, you might backup/restore these.
If it happens to return, I’ll be sure to file a bug.
Very well.
One last question: Data for the Storage section of the Global Utilization part of the
dashboard is empty. We are using Ceph via Cinder for our storage. Is that the issue?
I really have no idea, but it sounds reasonable. If you do not find an
existing open bug/RFE, please open one. Or start a new thread on this
list with a suitable subject header.
Side note: we are now being bitten by this bug -
https://bugzilla.redhat.com/show_bug.cgi?id=1465825
Thanks again for the assistance.
Charles
Best,
--
Didi
2675
days inactive
2679
days old
3 comments
2 participants
participants (2)
-
Charles Gruener -
Yedidyah Bar David