Description of problem: On our big scale setup we encountred this issue. 2017-08-16 13:28:00|FR4LuR|7QEs4P|C4FqAL|OVIRT_ENGINE_DWH|ConfigurationSync|Default|6|Java Exception|tJDBCOutput_6|org.postgresql.util.PSQLException:ERROR: value too long for type character varying(40)|1 Which appears after start/restart of dwh service Version-Release number of selected component (if applicable): ovirt-engine-dwh-4.1.1-1.el7ev.noarch How reproducible: 100% Steps to Reproduce: 1. Not sure (restart dwh service on big scale environment after long time running) Actual result: Dwh service running, but with error in log after restart. Additional info: [root@rhevm-3 ~]# systemctl status ovirt-engine-dwhd -l ● ovirt-engine-dwhd.service - oVirt Engine Data Warehouse Loaded: loaded (/usr/lib/systemd/system/ovirt-engine-dwhd.service; enabled; vendor preset: disabled) Active: active (running) since Wed 2017-08-16 12:40:15 IDT; 45min ago Main PID: 17192 (ovirt-engine-dw) CGroup: /system.slice/ovirt-engine-dwhd.service ├─17192 /usr/bin/python /usr/share/ovirt-engine-dwh/services/ovirt-engine-dwhd/ovirt-engine-dwhd.py --redirect-output --systemd=notify start └─17297 ovirt-engine-dwhd -Dorg.ovirt.engine.dwh.settings=/tmp/tmpWH40xl/settings.properties -Xms1g -Xmx1g -classpath /usr/share/ovirt-engine-dwh/lib/*::/usr/share/java/dom4j.jar:/usr/share/java/apache-commons-collections.jar:/usr/share/java/postgresql-jdbc.jar ovirt_engine_dwh.historyetl_4_1.HistoryETL --context=Default Aug 16 12:40:15 rhevm-3.qa.lab.tlv.redhat.com systemd[1]: Starting oVirt Engine Data Warehouse... Aug 16 12:40:15 rhevm-3.qa.lab.tlv.redhat.com systemd[1]: Started oVirt Engine Data Warehouse. [root@rhevm-3 ~]# systemctl restart ovirt-engine-dwhd && tail -f /var/log/ovirt-engine-dwh/ovirt-engine-dwhd.log 2017-08-16 13:27:13|ETL Service Stopped 2017-08-16 13:27:14|ETL Service Started ovirtEngineDbDriverClass|org.postgresql.Driver ovirtEngineHistoryDbJdbcConnection|jdbc:postgresql://localhost:5432/ovirt_engine_history?sslfactory=org.postgresql.ssl.NonValidatingFactory hoursToKeepDaily|43800 hoursToKeepHourly|1440 ovirtEngineDbPassword|****** runDeleteTime|3 ovirtEngineDbJdbcConnection|jdbc:postgresql://localhost:5432/engine?sslfactory=org.postgresql.ssl.NonValidatingFactory runInterleave|20 limitRows|limit 1000 ovirtEngineHistoryDbUser|engine_history ovirtEngineDbUser|engine deleteIncrement|10 timeBetweenErrorEvents|300000 hoursToKeepSamples|24 deleteMultiplier|1000 lastErrorSent|2011-07-03 12:46:47.000000 etlVersion|4.1.1 dwhAggregationDebug|false dwhUuid|6d2456d9-da11-4239-91cf-5d93efd47aa1 ovirtEngineHistoryDbDriverClass|org.postgresql.Driver ovirtEngineHistoryDbPassword|********* Exception in component tJDBCOutput_6 org.postgresql.util.PSQLException: ERROR: value too long for type character varying(40) 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:417) at org.postgresql.jdbc2.AbstractJdbc2Statement.executeUpdate(AbstractJdbc2Statement.java:363) at ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync.tJDBCInput_6Process(ConfigurationSync.java:27631) at ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync.tJDBCInput_24Process(ConfigurationSync.java:25030) at ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync.tJDBCInput_5Process(ConfigurationSync.java:23087) at ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync.tJDBCInput_22Process(ConfigurationSync.java:21194) at ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync.tJDBCInput_4Process(ConfigurationSync.java:18622) at ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync.tJDBCInput_34Process(ConfigurationSync.java:16097) at ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync.tJDBCInput_33Process(ConfigurationSync.java:14895) at ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync.tJDBCInput_20Process(ConfigurationSync.java:13697) at ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync.tJDBCInput_3Process(ConfigurationSync.java:12325) at ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync.tJDBCInput_18Process(ConfigurationSync.java:11345) at ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync.tJDBCInput_1Process(ConfigurationSync.java:9812) at ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync.tJDBCInput_15Process(ConfigurationSync.java:8382) at ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync.tJDBCInput_2Process(ConfigurationSync.java:7015) at ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync.tJDBCInput_11Process(ConfigurationSync.java:6053) at ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync.tJDBCInput_9Process(ConfigurationSync.java:4288) at ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync$2.run(ConfigurationSync.java:60001) 2017-08-16 13:28:00|FR4LuR|7QEs4P|C4FqAL|OVIRT_ENGINE_DWH|ConfigurationSync|Default|6|Java Exception|tJDBCOutput_6|org.postgresql.util.PSQLException:ERROR: value too long for type character varying(40)|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-08-16 13:28:00|C4FqAL|7QEs4P|51CQpX|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)
Can you please configure pg to log all queries, and attach the query log after a dwh restart? Thanks.
The first line in the stack trace from dwh code is: at ovirt_engine_dwh.configurationsync_4_1.ConfigurationSync.tJDBCInput_6Process(ConfigurationSync.java:27631) insertedCount_tJDBCOutput_6 = insertedCount_tJDBCOutput_6+pstmt_tJDBCOutput_6.executeUpdate(); pstmt_tJDBCOutput_6 is: java.sql.PreparedStatement pstmt_tJDBCOutput_6 = connection_tJDBCOutput_6.prepareStatement(insert_tJDBCOutput_6); And insert_tJDBCOutput_6 is: String insert_tJDBCOutput_6 = "INSERT INTO " + "vm_configuration" + " (vm_id,vm_name,vm_description,vm_type,cluster_id,template_id,template_name,cpu_per_socket,number_of_sockets,memory_size_mb,operating_system,default_host,high_availability,initialized,stateless,fail_back,usb_policy,time_zone,vm_pool_id,vm_pool_name,created_by_user_id,cluster_configuration_version,default_host_configuration_version,create_date,update_date,delete_date) VALUES (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)"; So it's probably a failing insert to vm_configuration. Can't find anywhere in the source 'varying(40)'.
Not sure if possible this is production environment where we cant afford much. Thoughts gil?
(In reply to Lukas Svaty from comment #3) > Not sure if possible this is production environment where we cant afford > much. Thoughts gil? But you said you managed to reproduce on a scale env, no?
Only on this production environment of bigger scale.
Can you please check if you have any template name that is more than 40 chars? You can try this on the engine db: select original_template_name from vm_static where length(original_template_name) >= 40;
(In reply to Yedidyah Bar David from comment #7) > Can you please check if you have any template name that is more than 40 > chars? You can try this on the engine db: > > select original_template_name from vm_static where > length(original_template_name) >= 40; Yes, I see one result: engine=# select original_template_name from vm_static where length(original_template_name) >= 40; original_template_name -------------------------------------------- auto-tmp-v6gFEHRQ-miq-nightly-201708082000 (1 row)
OK, that's the bug. Didn't check the engine itself or the API. Engine db has: CREATE TABLE vm_static ( ... original_template_name character varying(255) DEFAULT NULL::character varying, ); So allows up to 255 chars. dwh db has: CREATE TABLE vm_configuration ( ... template_name VARCHAR(40), ... ); So allows only 40.
(In reply to Yedidyah Bar David from comment #9) > OK, that's the bug. > > Didn't check the engine itself or the API. > > Engine db has: > > CREATE TABLE vm_static ( > ... > original_template_name character varying(255) DEFAULT NULL::character > varying, > ); > > So allows up to 255 chars. > > dwh db has: > CREATE TABLE vm_configuration ( > ... > template_name VARCHAR(40), > ... > ); > > So allows only 40. Thanks for the quick analysis! I'm removing the Regression keyword has it seems to be a fresh template in the system. I will remove it till it will get resolved.
(In reply to Gil Klein from comment #10) > I'm removing the Regression keyword has it seems to be a fresh template in > the system. I will remove it till it will get resolved. Please update here if it was enough. I have no idea, but if this field keeps its value even if you remove the actual template, dwh will still fail. You can then manually update it to a shorter name (but no idea what implications this will have).
UI announces max 64chars when longer. We don't have longer name than 40chars in our DB (in brq).
1. Web admin does not support creating template with more than 40 characters 2. Updated name to 41 characters in database Dwh service started and working: ovirt-engine-dwh-4.1.6-1.el7ev.noarch ovirt-engine-dwh-setup-4.1.6-1.el7ev.noarch