Jira (PDB-4642) Puppet 2019.3 upgrade failure from 2019.2.2

36 views
Skip to first unread message

Selvakumar Azhagarsami (JIRA)

unread,
Feb 3, 2020, 8:35:05 PM2/3/20
to puppe...@googlegroups.com
Selvakumar Azhagarsami created an issue
 
PuppetDB / Bug PDB-4642
Puppet 2019.3 upgrade failure from 2019.2.2
Issue Type: Bug Bug
Assignee: Unassigned
Attachments: 2020-01-31T12.33.25 1100.install.log
Components: PuppetDB
Created: 2020/02/03 5:34 PM
Priority: Normal Normal
Reporter: Selvakumar Azhagarsami

During the upgrade from 2019.2.2 to 2019.3, pe-puppetdb service is failed to start with the error message "resource_events_20200123z" does not exist.

[m2020-01-31T12:43:01.508+11:00 - [Notice]: /Stage[main]/Puppet_enterprise::Puppetdb::Service/Puppet_enterprise::Trapperkeeper::Pe_service[puppetdb]/Exec[pe-puppetdb service full restart]: Triggered 'refresh' from 1 event [0m
 [1;31m2020-01-31T12:44:13.543+11:00 - [Error]: Systemd start for pe-puppetdb failed!
journalctl log for pe-puppetdb:
-- Logs begin at Mon 2019-12-23 23:25:01 AEDT, end at Fri 2020-01-31 12:44:13 AEDT. --
Jan 31 12:43:02 harmony3-d1.anu.edu.au systemd[1]: Starting pe-puppetdb Service...
Jan 31 12:43:37 harmony3-d1.anu.edu.au puppetdb[124158]: WARNING: An illegal reflective access operation has occurred
Jan 31 12:43:37 harmony3-d1.anu.edu.au puppetdb[124158]: WARNING: Illegal reflective access by dynapath.defaults$eval24067$fn__24068 to method java.net.URLClassLoader.addURL(java.net.URL)
Jan 31 12:43:37 harmony3-d1.anu.edu.au puppetdb[124158]: WARNING: Please consider reporting this to the maintainers of dynapath.defaults$eval24067$fn__24068
Jan 31 12:43:37 harmony3-d1.anu.edu.au puppetdb[124158]: WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
Jan 31 12:43:37 harmony3-d1.anu.edu.au puppetdb[124158]: WARNING: All illegal access operations will be denied in a future release
Jan 31 12:43:52 harmony3-d1.anu.edu.au puppetdb[124158]: The [database] classname config option has been retired and will be ignored.
Jan 31 12:43:52 harmony3-d1.anu.edu.au puppetdb[124158]: The [database] log-slow-statements config option has been retired and will be ignored.
Jan 31 12:43:52 harmony3-d1.anu.edu.au puppetdb[124158]: The [database] subprotocol config option has been retired and will be ignored.
Jan 31 12:44:04 harmony3-d1.anu.edu.au puppetdb[124158]: The [database] classname config option has been retired and will be ignored.
Jan 31 12:44:04 harmony3-d1.anu.edu.au puppetdb[124158]: The [database] log-slow-statements config option has been retired and will be ignored.
Jan 31 12:44:04 harmony3-d1.anu.edu.au puppetdb[124158]: The [database] subprotocol config option has been retired and will be ignored.
Jan 31 12:44:13 harmony3-d1.anu.edu.au puppetdb[124158]: Execution error (PSQLException) at org.postgresql.core.v3.QueryExecutorImpl/receiveErrorResponse (QueryExecutorImpl.java:2497).
Jan 31 12:44:13 harmony3-d1.anu.edu.au puppetdb[124158]: ERROR: relation "resource_events_20200123z" does not exist
Jan 31 12:44:13 harmony3-d1.anu.edu.au puppetdb[124158]: Position: 13
Jan 31 12:44:13 harmony3-d1.anu.edu.au puppetdb[124158]: Full report at:
Jan 31 12:44:13 harmony3-d1.anu.edu.au puppetdb[124158]: /tmp/clojure-9861888815849128723.edn
Jan 31 12:44:13 harmony3-d1.anu.edu.au systemd[1]: pe-puppetdb.service: control process exited, code=exited status=1
Jan 31 12:44:13 harmony3-d1.anu.edu.au systemd[1]: Failed to start pe-puppetdb Service.
Jan 31 12:44:13 harmony3-d1.anu.edu.au systemd[1]: Unit pe-puppetdb.service entered failed state.
Jan 31 12:44:13 harmony3-d1.anu.edu.au systemd[1]: pe-puppetdb.service failed.
 [0m
 [1;31m2020-01-31T12:44:13.545+11:00 - [Error]: /Stage[main]/Puppet_enterprise::Puppetdb::Service/Puppet_enterprise::Trapperkeeper::Pe_service[puppetdb]/Service[pe-puppetdb]/ensure: change from 'stopped' to 'running' failed: Systemd start for pe-puppetdb failed!
journalctl log for pe-puppetdb: 

Add Comment Add Comment
 
This message was sent by Atlassian JIRA (v7.7.1#77002-sha1:e75ca93)
Atlassian logo

Selvakumar Azhagarsami (JIRA)

unread,
Feb 3, 2020, 8:36:04 PM2/3/20
to puppe...@googlegroups.com
Selvakumar Azhagarsami updated an issue
Change By: Selvakumar Azhagarsami
During the upgrade from 2019.2.2 to 2019.3, pe-puppetdb service is failed to start with the error message "resource_events_20200123z" does not exist. Please refer to the attached log file for more details.
{code:java}[m2020-01-31T12:43:01.508+11:00 - [Notice]: /Stage[main]/Puppet_enterprise::Puppetdb::Service/Puppet_enterprise::Trapperkeeper::Pe_service[puppetdb]/Exec[pe-puppetdb service full restart]: Triggered 'refresh' from 1 event [0m
journalctl log for pe-puppetdb: {code}

Selvakumar Azhagarsami (JIRA)

unread,
Feb 3, 2020, 8:36:04 PM2/3/20
to puppe...@googlegroups.com
Selvakumar Azhagarsami updated an issue
During the upgrade from 2019.2.2 to 2019.3, pe-puppetdb service is failed to start with the error message "resource_events_20200123z" does not exist.
{code:java}

Selvakumar Azhagarsami (JIRA)

unread,
Feb 3, 2020, 8:39:03 PM2/3/20
to puppe...@googlegroups.com
Selvakumar Azhagarsami updated an issue
During the upgrade from 2019.2.2 to 2019.3, pe-puppetdb service is failed to start with the error message "resource_events_20200123z" does not exist. Please refer to the attached log file for more details.

 

The customer was successfully upgraded after they truncate the resource_event table manually.
{code:java}
root@harmony3-d1:/# puppet infra status
Notice: Contacting services for status information...
Code Manager: Running on Primary Master, https://harmony3-d1.anu.edu.au:8170/
File Sync Storage Service: Running on Primary Master, https://harmony3-d1.anu.edu.au:8140/
File Sync Client Service: Running on Primary Master, https://harmony3-d1.anu.edu.au:8140/
Puppet Server: Running on Primary Master, https://harmony3-d1.anu.edu.au:8140/
Classifier: Running on Primary Master, https://harmony3-d1.anu.edu.au:4433/classifier-api
RBAC: Running on Primary Master, https://harmony3-d1.anu.edu.au:4433/rbac-api
Activity Service: Running on Primary Master, https://harmony3-d1.anu.edu.au:4433/activity-api
Orchestrator: Running on Primary Master, https://harmony3-d1.anu.edu.au:8143/orchestrator
PCP Broker: Running on Primary Master, wss://harmony3-d1.anu.edu.au:8142/pcp
PCP Broker v2: Running on Primary Master, wss://harmony3-d1.anu.edu.au:8142/pcp2
PuppetDB: Running on Primary Master, https://harmony3-d1.anu.edu.au:8081/pdb
2020-02-04 10:17:59 +1100
11 of 11 services are fully operational. {code}
 

 

Selvakumar Azhagarsami (JIRA)

unread,
Feb 3, 2020, 8:40:04 PM2/3/20
to puppe...@googlegroups.com

Selvakumar Azhagarsami (JIRA)

unread,
Feb 3, 2020, 8:41:03 PM2/3/20
to puppe...@googlegroups.com

Austin Boyd (JIRA)

unread,
Feb 3, 2020, 8:42:03 PM2/3/20
to puppe...@googlegroups.com
Austin Boyd updated an issue
 
Change By: Austin Boyd
Zendesk Ticket IDs: 37911
Zendesk Ticket Count: 1

Austin Boyd (JIRA)

unread,
Feb 3, 2020, 8:42:04 PM2/3/20
to puppe...@googlegroups.com
Austin Boyd updated an issue
Change By: Austin Boyd
Labels: jira_escalated

Selvakumar Azhagarsami (JIRA)

unread,
Feb 3, 2020, 8:45:04 PM2/3/20
to puppe...@googlegroups.com
Selvakumar Azhagarsami updated an issue
Change By: Selvakumar Azhagarsami
Attachment: 2020-01-31T12.33.25 1100.install.log

Selvakumar Azhagarsami (JIRA)

unread,
Feb 3, 2020, 8:45:04 PM2/3/20
to puppe...@googlegroups.com
Selvakumar Azhagarsami updated an issue
The customer was successfully upgraded after they truncate truncating the resource_event table manually.

{code:java}root@harmony3-d1:/# puppet infra status
Notice: Contacting services for status information...
Code Manager: Running on Primary Master ,  https://harmony3-d1.anu.edu.au:8170/

File Sync Storage Service: Running on Primary Master, https://harmony3-d1.anu.edu.au:8140/
File Sync Client Service: Running on Primary Master, https://harmony3-d1.anu.edu.au:8140/
Puppet Server: Running on Primary Master, https://harmony3-d1.anu.edu.au:8140/
Classifier: Running on Primary Master, https://harmony3-d1.anu.edu.au:4433/classifier-api
RBAC: Running on Primary Master, https://harmony3-d1.anu.edu.au:4433/rbac-api
Activity Service: Running on Primary Master, https://harmony3-d1.anu.edu.au:4433/activity-api
Orchestrator: Running on Primary Master, https://harmony3-d1.anu.edu.au:8143/orchestrator
PCP Broker: Running on Primary Master, wss://harmony3-d1.anu.edu.au:8142/pcp
PCP Broker v2: Running on Primary Master, wss://harmony3-d1.anu.edu.au:8142/pcp2
PuppetDB: Running on Primary Master, https://harmony3-d1.anu.edu.au:8081/pdb
2020-02-04 10:17:59 +1100
11 of 11 the upgrade was successful and all the services are fully operational up and running . {code}
 

 

Selvakumar Azhagarsami (JIRA)

unread,
Feb 3, 2020, 8:55:04 PM2/3/20
to puppe...@googlegroups.com
Selvakumar Azhagarsami updated an issue
During the upgrade from 2019.2.2 to 2019.3, pe-puppetdb service is failed to start with the error message "resource_events_20200123z" does not exist. Please refer to the attached log file for more details.
{code:java}[m2020-01-31T12:43:01.508+11:00 - [Notice]: /Stage[main]/Puppet_enterprise::Puppetdb::Service/Puppet_enterprise::Trapperkeeper::Pe_service[puppetdb]/Exec[pe-puppetdb service full restart]: Triggered 'refresh' from 1 event [0m
[1;31m2020-01-31T12:44:13.543+11:00 - [Error]: Systemd start for pe-puppetdb failed!
journalctl log for pe-puppetdb:
-- Logs begin at Mon 2019-12-23 23:25:01 AEDT, end at Fri 2020-01-31 12:44:13 AEDT. --
Jan 31 12:43:02 harmony3-d1 puppetlabs . anu.edu.au com systemd[1]: Starting pe-puppetdb Service...
Jan 31 12:43:37
harmony3-d1 puppetlabs . anu.edu.au com puppetdb[124158]: WARNING: An illegal reflective access operation has occurred
Jan 31 12:43:37
harmony3-d1 puppetlabs . anu.edu.au com puppetdb[124158]: WARNING: Illegal reflective access by dynapath.defaults$eval24067$fn__24068 to method java.net.URLClassLoader.addURL(java.net.URL)
Jan 31 12:43:37
harmony3-d1 puppetlabs . anu.edu.au com puppetdb[124158]: WARNING: Please consider reporting this to the maintainers of dynapath.defaults$eval24067$fn__24068
Jan 31 12:43:37
harmony3-d1 puppetlabs . anu.edu.au com puppetdb[124158]: WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
Jan 31 12:43:37
harmony3-d1 puppetlabs . anu.edu.au com puppetdb[124158]: WARNING: All illegal access operations will be denied in a future release
Jan 31 12:43:52
harmony3-d1 puppetlabs . anu.edu.au com puppetdb[124158]: The [database] classname config option has been retired and will be ignored.
Jan 31 12:43:52
harmony3-d1 puppetlabs . anu.edu.au com puppetdb[124158]: The [database] log-slow-statements config option has been retired and will be ignored.
Jan 31 12:43:52
harmony3-d1 puppetlabs . anu.edu.au com puppetdb[124158]: The [database] subprotocol config option has been retired and will be ignored.
Jan 31 12:44:04
harmony3-d1 puppetlabs . anu.edu.au com puppetdb[124158]: The [database] classname config option has been retired and will be ignored.
Jan 31 12:44:04
harmony3-d1 puppetlabs . anu.edu.au com puppetdb[124158]: The [database] log-slow-statements config option has been retired and will be ignored.
Jan 31 12:44:04
harmony3-d1 puppetlabs . anu.edu.au com puppetdb[124158]: The [database] subprotocol config option has been retired and will be ignored.
Jan 31 12:44:13
harmony3-d1 puppetlabs . anu.edu.au com puppetdb[124158]: Execution error (PSQLException) at org.postgresql.core.v3.QueryExecutorImpl/receiveErrorResponse (QueryExecutorImpl.java:2497).
Jan 31 12:44:13
harmony3-d1 puppetlabs . anu.edu.au com puppetdb[124158]: ERROR: relation "resource_events_20200123z" does not exist
Jan 31 12:44:13
harmony3-d1 puppetlabs . anu.edu.au com puppetdb[124158]: Position: 13
Jan 31 12:44:13
harmony3-d1 puppetlabs . anu.edu.au com puppetdb[124158]: Full report at:
Jan 31 12:44:13
harmony3-d1 puppetlabs . anu.edu.au com puppetdb[124158]: /tmp/clojure-9861888815849128723.edn
Jan 31 12:44:13
harmony3-d1 puppetlabs . anu.edu.au com systemd[1]: pe-puppetdb.service: control process exited, code=exited status=1
Jan 31 12:44:13
harmony3-d1 puppetlabs . anu.edu.au com systemd[1]: Failed to start pe-puppetdb Service.
Jan 31 12:44:13
harmony3-d1 puppetlabs . anu.edu.au com systemd[1]: Unit pe-puppetdb.service entered failed state.
Jan 31 12:44:13
harmony3-d1 puppetlabs . anu.edu.au com systemd[1]: pe-puppetdb.service failed.

[0m
[1;31m2020-01-31T12:44:13.545+11:00 - [Error]: /Stage[main]/Puppet_enterprise::Puppetdb::Service/Puppet_enterprise::Trapperkeeper::Pe_service[puppetdb]/Service[pe-puppetdb]/ensure: change from 'stopped' to 'running' failed: Systemd start for pe-puppetdb failed!
journalctl log for pe-puppetdb: {code}
 

after truncating the resource_event table, the upgrade was successful and all the services are up and running. 

 

Jarret Lavallee (JIRA)

unread,
Feb 4, 2020, 12:01:05 PM2/4/20
to puppe...@googlegroups.com
Jarret Lavallee updated an issue
Change By: Jarret Lavallee
CS Priority: Needs Priority

Paul Reed (JIRA)

unread,
Feb 6, 2020, 4:00:04 PM2/6/20
to puppe...@googlegroups.com
Paul Reed updated an issue
Change By: Paul Reed
Attachment: PDB-4642-psreed.zip

Paul Reed (JIRA)

unread,
Feb 6, 2020, 4:02:04 PM2/6/20
to puppe...@googlegroups.com
Paul Reed commented on Bug PDB-4642
 
Re: Puppet 2019.3 upgrade failure from 2019.2.2

Seems I've run into a similar issue. I've attached a zipfile with a copy of my resource_events table, as well as the pertinent bits from /var/log/messages and the clojure EDN file referenced in the error. Hopefully this will help.

Thanks,

Paul

Charlie Sharpsteen (JIRA)

unread,
Feb 6, 2020, 6:03:04 PM2/6/20
to puppe...@googlegroups.com
Charlie Sharpsteen updated an issue
 
Change By: Charlie Sharpsteen
Attachment: resource_events_migration.log

Charlie Sharpsteen (JIRA)

unread,
Feb 6, 2020, 6:03:05 PM2/6/20
to puppe...@googlegroups.com
Charlie Sharpsteen commented on Bug PDB-4642
 
Re: Puppet 2019.3 upgrade failure from 2019.2.2

I can re-produce this using the ZIP archive that Paul Reed uploaded:

  • Get a CentOS 8 VM
  • Set the timezone to EST: timedatectl set-timezone 'America/New_York'
  • Install PE 2019.2.2
  • Stop PuppetDB: systemctl stop pe-puppetdb
  • Drop the resource_events table:

sudo -u pe-postgres /opt/puppetlabs/server/bin/psql -d pe-puppetdb -c 'drop table resource_events'

  • Unpack the ZIP archive, copy resource_events.sql somewhere world-readable, like /tmp, and edit it to remove the last statement (otherwise, import fails):

ALTER TABLE ONLY public.resource_events
    ADD CONSTRAINT resource_events_report_id_fkey FOREIGN KEY (report_id) REFERENCES public.reports(id) ON DELETE CASCADE;

  • Import the edited copy of resource_events.sql:

sudo -u pe-postgres /opt/puppetlabs/server/bin/psql -d pe-puppetdb -f /tmp/resource_events.sql

  • Upgrade to 2019.3.0

During the upgrade, pe-puppetdb should fail to start with:

ERROR: relation "resource_events_20200131z" does not exist

I configured Postgres with log_statement='all' and log_min_duration_statement=0 to capture all statements generated during the migration. Logs attached resource_events_migration.log

Charlie Sharpsteen (JIRA)

unread,
Feb 6, 2020, 6:11:03 PM2/6/20
to puppe...@googlegroups.com

The migration does not create a table for Jan 31st:

grep -o '\(CREATE TABLE IF NOT EXISTS [^[:space:]]\+\)' resource_events_migration.log|sort -u
CREATE TABLE IF NOT EXISTS resource_events_20200123Z
CREATE TABLE IF NOT EXISTS resource_events_20200124Z
CREATE TABLE IF NOT EXISTS resource_events_20200130Z
CREATE TABLE IF NOT EXISTS resource_events_20200202Z
CREATE TABLE IF NOT EXISTS resource_events_20200203Z
CREATE TABLE IF NOT EXISTS resource_events_20200204Z
CREATE TABLE IF NOT EXISTS resource_events_20200205Z
CREATE TABLE IF NOT EXISTS resource_events_20200206Z
CREATE TABLE IF NOT EXISTS resource_events_20200207Z
CREATE TABLE IF NOT EXISTS resource_events_20200208Z
CREATE TABLE IF NOT EXISTS resource_events_20200209Z

But then attempts an insert into that partition:

grep -o '\(INSERT INTO resource_events_[^[:space:]]\+\)' resource_events_migration.log|sort -u
INSERT INTO resource_events_20200124Z
INSERT INTO resource_events_20200131Z

Jarret Lavallee (JIRA)

unread,
Feb 6, 2020, 7:33:04 PM2/6/20
to puppe...@googlegroups.com
Jarret Lavallee updated an issue
 
Change By: Jarret Lavallee
CS Priority: Needs Priority Major

Jarret Lavallee (JIRA)

unread,
Feb 6, 2020, 7:39:03 PM2/6/20
to puppe...@googlegroups.com

Austin Boyd (JIRA)

unread,
Feb 9, 2020, 9:02:04 PM2/9/20
to puppe...@googlegroups.com
Austin Boyd updated an issue
Change By: Austin Boyd
Zendesk Ticket IDs: 37911 ,38027
Zendesk Ticket Count: 1 2

Jeffrey Pistone (JIRA)

unread,
Feb 11, 2020, 11:22:06 AM2/11/20
to puppe...@googlegroups.com

Charlie Sharpsteen (JIRA)

unread,
Feb 11, 2020, 2:54:05 PM2/11/20
to puppe...@googlegroups.com

This issue appears to be caused by PuppetDB running migrations in a non-UTC timezone. One workaround that doesn't require truncating the resource events table is to temporarily run PuppetDB with the timezone set to UTC:

 

  1. On RedHat 6: service pe-puppetdb stop
    systemctl stop pe-puppetdb

/usr/bin/env TZ=utc /opt/puppetlabs/server/bin/puppetdb foreground

  1. Use Ctrl-C to stop PuppetDB after "PDBMigrationsPool - Shutdown completed" is logged
  1. On RedHat 6: service pe-puppetdb start
    systemctl start pe-puppetdb {bash}

The above steps should work for Open Source PuppetDB 6.8.1 as well, use puppetdb as the service name instead of pe-puppetdb.

Melissa Amos (JIRA)

unread,
Feb 12, 2020, 6:14:05 PM2/12/20
to puppe...@googlegroups.com
Melissa Amos commented on Bug PDB-4642

Ah right. That's the one you pinged us on yesterday. Thanks Charlie Sharpsteen!

Reply all
Reply to author
Forward
0 new messages