puppetdb fails to start after switching to v8.1.0

[vchepkov]

Describe the Bug

Upgrading to module v8.1.0 renders puppetdb unoperational , service doesn't start
The following log entries are observed in puppetdb.log

2024-06-01T14:24:13.865Z INFO  [p.p.c.services] PuppetDB version 8.5.1
2024-06-01T14:24:13.867Z INFO  [p.p.c.services] Ensuring default database is up to date
2024-06-01T14:24:13.869Z INFO  [c.z.h.HikariDataSource] PDBMigrationsPool: default - Starting...
2024-06-01T14:24:13.883Z INFO  [c.z.h.HikariDataSource] PDBMigrationsPool: default - Start completed.
2024-06-01T14:24:16.900Z ERROR [p.p.c.services] Will retry database connection after temporary failure: java.sql.SQLTransientConnectionException: PDBMigrationsPool: default - Connection is not available, request timed out after 3014ms.
2024-06-01T14:24:19.900Z ERROR [p.p.c.services] Will retry database connection after temporary failure: java.sql.SQLTransientConnectionException: PDBMigrationsPool: default - Connection is not available, request timed out after 3000ms.

Reverting back to v8.0.1 restores functionality

Environment

postgresql14-libs-14.12-1PGDG.rhel9.x86_64
postgresql14-14.12-1PGDG.rhel9.x86_64
postgresql14-server-14.12-1PGDG.rhel9.x86_64
postgresql14-contrib-14.12-1PGDG.rhel9.x86_64
puppet8-release-1.0.0-8.el9.noarch
puppet-agent-8.6.0-1.el9.x86_64
puppetdb-termini-8.5.1-1.el9.noarch
puppetserver-8.6.0-1.el9.noarch
puppetdb-8.5.1-1.el9.noarch

AlmaLinux 9.4

[Geod24]

Duplicate of #413

[smortex]

@vchepkov If the service fail to restart, there are corrective changes right? What are they?

Also the message indicate that the server cannot reach the database in 3s and timeout. Have you tried to measure how long it take to connect? Maybe some changes delay the connection and a raising the value way workaround the issue?

[vchepkov]

That's a good question. I only used it for bootstrap and it didn't start. I will try to see, what correction v8.0.1 will do

[vchepkov]

PuppetDB runs on the same server as database, so, there is no any delay

[vchepkov]

From what I can tell, only permissions on configuration files are changing and puppetdb is still operational

Info: Using environment 'production'
Info: Retrieving pluginfacts
Info: Retrieving plugin
Notice: /File[/opt/puppetlabs/puppet/cache/lib/facter/puppetdb_version.rb]/ensure: removed
Info: Loading facts
Notice: Requesting catalog from puppet.localdomain:8140 (192.168.56.20)
Notice: Catalog compiled by puppet.localdomain
Info: Caching catalog for puppet.localdomain
Info: Applying configuration version '076addd'
Notice: /Stage[main]/Puppetdb::Server::Database/File[/etc/puppetlabs/puppetdb/conf.d/database.ini]/owner: owner changed 'root' to 'puppetdb'
Notice: /Stage[main]/Puppetdb::Server::Database/File[/etc/puppetlabs/puppetdb/conf.d/database.ini]/mode: mode changed '0640' to '0600'
Info: Class[Puppetdb::Server::Database]: Scheduling refresh of Service[puppetdb]
Notice: /Stage[main]/Puppetdb::Server::Read_database/File[/etc/puppetlabs/puppetdb/conf.d/read_database.ini]/owner: owner changed 'root' to 'puppetdb'
Notice: /Stage[main]/Puppetdb::Server::Read_database/File[/etc/puppetlabs/puppetdb/conf.d/read_database.ini]/mode: mode changed '0640' to '0600'
Info: Class[Puppetdb::Server::Read_database]: Scheduling refresh of Service[puppetdb]
Notice: /Stage[main]/Puppetdb::Server::Jetty/File[/etc/puppetlabs/puppetdb/conf.d/jetty.ini]/owner: owner changed 'root' to 'puppetdb'
Notice: /Stage[main]/Puppetdb::Server::Jetty/File[/etc/puppetlabs/puppetdb/conf.d/jetty.ini]/mode: mode changed '0640' to '0600'
Info: Class[Puppetdb::Server::Jetty]: Scheduling refresh of Service[puppetdb]
Notice: /Stage[main]/Puppetdb::Server::Puppetdb/File[/etc/puppetlabs/puppetdb/conf.d/puppetdb.ini]/owner: owner changed 'root' to 'puppetdb'
Notice: /Stage[main]/Puppetdb::Server::Puppetdb/File[/etc/puppetlabs/puppetdb/conf.d/puppetdb.ini]/mode: mode changed '0640' to '0600'
Info: Class[Puppetdb::Server::Puppetdb]: Scheduling refresh of Service[puppetdb]
Notice: /Stage[main]/Puppetdb::Server/Service[puppetdb]: Triggered 'refresh' from 4 events
Info: Stage[main]: Unscheduling all events on Stage[main]
Notice: Applied catalog in 12.20 seconds

But if you start with v8.1.0, puppetdb service doesn't start, strange

[vchepkov]

@smortex , this code has a logic flaw

  $puppetdb_major_version = $puppetdb_version ? {
    'latest'  => '8',
    'present' => '8',
    default   => $puppetdb_version.split('.')[0],
  }

Since puppetdb is not installed yet during initial run, puppetdb_version is nil, and split probably provides not the result one would expect

P.S. never mind, it's a variable too

[smortex]

PuppetDB runs on the same server as database, so, there is no any delay

Could be a missing ordering dependency? Configure the database and only then attempt to start PuppetDB that need it?

[vchepkov]

I am not sure, wasn't able to find a culrpit yet. You can easily reproduce it using a vagrant project:
https://github.com/vchepkov/puppet-bootstrap

PUPPET_ENV=puppetdb vagrant up

[kenyon]

In case anyone else messes up their system with v8.1.0 of puppetlabs-puppetdb, I was able to recover (on Debian 11) by setting the puppetlabs-puppetdb version to 8.0.1 in Puppetfile, doing an r10k deploy, then basically used the procedure here, thanks to @tuxmea: https://groups.google.com/g/puppet-users/c/pc-cHV-0lBY/m/z1CHUTBFBAAJ

sudo systemctl stop puppetdb
sudo aptitude purge puppetdb
sudo mv -vi /etc/puppetlabs/puppetdb /etc/puppetlabs/puppet/{puppetdb.conf,routes.yaml} /tmp
sudo systemctl restart postgresql
sudo puppet agent --test

[vchepkov]

I have compared the catalogs produced by 8.0.1 and 8.1.0

     puppet: Notice: /Stage[main]/Postgresql::Server::Reload/Postgresql::Server::Instance::Reload[main]/Exec[postgresql_reload_main]: Triggered 'refresh' from 1 event
     puppet: Notice: /Stage[main]/Puppetdb::Database::Postgresql/Postgresql::Server::Db[puppetdb]/Postgresql::Server::Role[puppetdb]/Postgresql_psql[CREATE ROLE puppetdb ENCRYPTED PASSWORD ****]/command: changed [redacted] to [redacted]
     puppet: Notice: /Stage[main]/Puppetdb::Database::Postgresql/Postgresql::Server::Db[puppetdb]/Postgresql::Server::Role[puppetdb]/Postgresql_psql[ALTER ROLE puppetdb ENCRYPTED PASSWORD ****]/command: changed [redacted] to [redacted]
-    puppet: Notice: /Stage[main]/Puppetdb::Database::Postgresql/Postgresql::Server::Db[puppetdb]/Postgresql::Server::Database[puppetdb]/Postgresql_psql[CREATE DATABASE "puppetdb"]/command: command changed 'notrun' to 'CREATE DATABASE "puppetdb" WITH TEMPLATE = "template0"   '
+    puppet: Notice: /Stage[main]/Puppetdb::Database::Postgresql/Postgresql::Server::Db[puppetdb]/Postgresql::Server::Database[puppetdb]/Postgresql_psql[CREATE DATABASE "puppetdb"]/command: command changed 'notrun' to 'CREATE DATABASE "puppetdb" WITH TEMPLATE = "template0" ENCODING = \'UTF8\' LC_COLLATE = \'en_US.UTF-8\' LC_CTYPE = \'en_US.UTF-8\' '
     puppet: Notice: /Stage[main]/Puppetdb::Database::Postgresql/Postgresql::Server::Db[puppetdb]/Postgresql::Server::Database[puppetdb]/Postgresql_psql[REVOKE CONNECT ON DATABASE "puppetdb" FROM public]: Triggered 'refresh' from 1 event
+    puppet: Notice: /Stage[main]/Puppetdb::Database::Postgresql/Postgresql::Server::Db[puppetdb]/Postgresql::Server::Database[puppetdb]/Postgresql_psql[UPDATE pg_database SET datistemplate = false WHERE datname = 'puppetdb']/command: command changed 'notrun' to 'UPDATE pg_database SET datistemplate = false WHERE datname = \'puppetdb\''
     puppet: Notice: /Stage[main]/Puppetdb::Database::Postgresql/Postgresql::Server::Db[puppetdb]/Postgresql::Server::Database_grant[GRANT puppetdb - all - puppetdb]/Postgresql::Server::Grant[database:GRANT puppetdb - all - puppetdb]/Postgresql_psql[grant:database:GRANT puppetdb - all - puppetdb]/command: command changed 'notrun' to 'GRANT ALL ON DATABASE "puppetdb" TO "puppetdb"'
     puppet: Notice: /Stage[main]/Puppetdb::Database::Postgresql/Postgresql_psql[revoke all access on public schema]/command: command changed 'notrun' to 'REVOKE CREATE ON SCHEMA public FROM public'
     puppet: Notice: /Stage[main]/Puppetdb::Database::Postgresql/Postgresql_psql[grant all permissions to puppetdb]/command: command changed 'notrun' to 'GRANT CREATE ON SCHEMA public TO "puppetdb"'
@@ -61,13 +62,15 @@
     puppet: Notice: /Stage[main]/Puppetdb::Database::Postgresql/Puppetdb::Database::Read_only_user[puppetdb-read]/Puppetdb::Database::Default_read_grant[puppetdb grant read permission on new objects from puppetdb to puppetdb-read]/Postgresql_psql[grant default select permission for puppetdb-read]/command: command changed 'notrun' to "ALTER DEFAULT PRIVILEGES\n                  FOR USER \"puppetdb\"\n                  IN SCHEMA \"public\"\n                GRANT SELECT ON TABLES\n                  TO \"puppetdb-read\""
     puppet: Notice: /Stage[main]/Puppetdb::Database::Postgresql/Puppetdb::Database::Read_only_user[puppetdb-read]/Puppetdb::Database::Default_read_grant[puppetdb grant read permission on new objects from puppetdb to puppetdb-read]/Postgresql_psql[grant default usage permission for puppetdb-read]/command: command changed 'notrun' to "ALTER DEFAULT PRIVILEGES\n                  FOR USER \"puppetdb\"\n                  IN SCHEMA \"public\"\n                GRANT USAGE ON SEQUENCES\n                  TO \"puppetdb-read\""
     puppet: Notice: /Stage[main]/Puppetdb::Database::Postgresql/Puppetdb::Database::Read_only_user[puppetdb-read]/Puppetdb::Database::Default_read_grant[puppetdb grant read permission on new objects from puppetdb to puppetdb-read]/Postgresql_psql[grant default execute permission for puppetdb-read]/command: command changed 'notrun' to "ALTER DEFAULT PRIVILEGES\n                  FOR USER \"puppetdb\"\n                  IN SCHEMA \"public\"\n                GRANT EXECUTE ON FUNCTIONS\n                  TO \"puppetdb-read\""
+    puppet: Notice: /Stage[main]/Puppetdb::Database::Postgresql/Puppetdb::Database::Read_only_user[puppetdb-read]/Puppetdb::Database::Read_grant[puppetdb grant read-only permission on existing objects to puppetdb-read]/Postgresql_psql[grant select permission for puppetdb-read]/command: command changed 'notrun' to "GRANT SELECT\n                ON ALL TABLES IN SCHEMA \"public\"\n                TO \"puppetdb-read\""
+    puppet: Notice: /Stage[main]/Puppetdb::Database::Postgresql/Puppetdb::Database::Read_only_user[puppetdb-read]/Puppetdb::Database::Read_grant[puppetdb grant read-only permission on existing objects to puppetdb-read]/Postgresql_psql[grant usage permission for puppetdb-read]/command: command changed 'notrun' to "GRANT USAGE\n                ON ALL SEQUENCES IN SCHEMA \"public\"\n                TO \"puppetdb-read\""
+    puppet: Notice: /Stage[main]/Puppetdb::Database::Postgresql/Puppetdb::Database::Read_only_user[puppetdb-read]/Puppetdb::Database::Read_grant[puppetdb grant read-only permission on existing objects to puppetdb-read]/Postgresql_psql[grant execution permission for puppetdb-read]/command: command changed 'notrun' to "GRANT EXECUTE\n                ON ALL FUNCTIONS IN SCHEMA \"public\"\n                TO \"puppetdb-read\""
     puppet: Notice: /Stage[main]/Puppetdb::Database::Postgresql/Postgresql_psql[grant puppetdb-read role to puppetdb]/command: command changed 'notrun' to 'GRANT "puppetdb-read" TO "puppetdb"'
     puppet: Notice: /Stage[main]/Puppetdb::Server/Package[puppetdb]/ensure: created
     puppet: Notice: /Stage[main]/Puppetdb::Server::Global/File[/etc/puppetlabs/puppetdb/conf.d/config.ini]/group: group changed 'root' to 'puppetdb'
     puppet: Notice: /Stage[main]/Puppetdb::Server::Global/File[/etc/puppetlabs/puppetdb/conf.d/config.ini]/mode: mode changed '0644' to '0640'
-    puppet: Notice: /Stage[main]/Puppetdb::Server::Database/File[/etc/puppetlabs/puppetdb/conf.d/database.ini]/owner: owner changed 'root' to 'puppetdb'
     puppet: Notice: /Stage[main]/Puppetdb::Server::Database/File[/etc/puppetlabs/puppetdb/conf.d/database.ini]/group: group changed 'root' to 'puppetdb'
-    puppet: Notice: /Stage[main]/Puppetdb::Server::Database/File[/etc/puppetlabs/puppetdb/conf.d/database.ini]/mode: mode changed '0644' to '0600'
+    puppet: Notice: /Stage[main]/Puppetdb::Server::Database/File[/etc/puppetlabs/puppetdb/conf.d/database.ini]/mode: mode changed '0644' to '0640'
     puppet: Notice: /Stage[main]/Puppetdb::Server::Database/Ini_setting[puppetdb_psdatabase_username]/ensure: created
     puppet: Notice: /Stage[main]/Puppetdb::Server::Database/Ini_setting[puppetdb_psdatabase_password]/ensure: created
     puppet: Notice: /Stage[main]/Puppetdb::Server::Database/Ini_setting[puppetdb_pgs]/ensure: created
@@ -87,9 +90,8 @@
     puppet: Notice: /Stage[main]/Puppetdb::Server::Read_database/Ini_setting[puppetdb_read_subname]/ensure: created
     puppet: Notice: /Stage[main]/Puppetdb::Server::Read_database/Ini_setting[puppetdb_read_conn_max_age]/ensure: created
     puppet: Notice: /Stage[main]/Puppetdb::Server::Read_database/Ini_setting[puppetdb_read_conn_lifetime]/ensure: created
-    puppet: Notice: /Stage[main]/Puppetdb::Server::Jetty/File[/etc/puppetlabs/puppetdb/conf.d/jetty.ini]/owner: owner changed 'root' to 'puppetdb'
     puppet: Notice: /Stage[main]/Puppetdb::Server::Jetty/File[/etc/puppetlabs/puppetdb/conf.d/jetty.ini]/group: group changed 'root' to 'puppetdb'
-    puppet: Notice: /Stage[main]/Puppetdb::Server::Jetty/File[/etc/puppetlabs/puppetdb/conf.d/jetty.ini]/mode: mode changed '0644' to '0600'
+    puppet: Notice: /Stage[main]/Puppetdb::Server::Jetty/File[/etc/puppetlabs/puppetdb/conf.d/jetty.ini]/mode: mode changed '0644' to '0640'
     puppet: Notice: /Stage[main]/Puppetdb::Server::Jetty/File[/etc/puppetlabs/puppetdb/conf.d/jetty.ini]/seluser: seluser changed 'unconfined_u' to 'system_u'
     puppet: Notice: /Stage[main]/Puppetdb::Server::Jetty/Ini_setting[puppetdb_host]/ensure: created
     puppet: Notice: /Stage[main]/Puppetdb::Server::Jetty/Ini_setting[puppetdb_sslprotocols]/ensure: created

[kenyon]

@vchepkov nice, I'd guess the issue is in the changes to the SQL code, I'm assuming the file mode changes are innocuous.

[vchepkov]

Right, so the command create database fails and that fact doesn't get detected by puppet

postgres=# CREATE DATABASE "puppetdb" WITH TEMPLATE = "template0" ENCODING = 'UTF8' LC_COLLATE = 'en_US.UTF-8' LC_CTYPE = 'en_US.UTF-8';
ERROR:  invalid locale name: "en_US.UTF-8"

It makes an assumption that locale is installed, but it's not, by default

[postgres@puppet ~]$ locale -a
C
C.utf8
POSIX

So, if module wants to use this locale, it should make sure glibc-langpack-en is installed before postgresql started

https://github.com/puppetlabs/puppetlabs-puppetdb/blob/main/manifests/database/postgresql.pp#L153

[d1nuc0m]

INFO: the responsible commit is 0c5c270

And a question, why is not possible to use C as locale?

Adding the package in question does not seem to be enough, the puppetdb still hangs

package { 'glibc-langpack-en':
  before => Class['puppetdb'],
}

[saimonn]

I'm observing the same problem on a rhel-8 where the locale en_US.UTF-8 is not installed.

Changing the locale to C.UTF-8 in source of the module fixes it.

The en_US.UTF-8 was arbitrary chosen in commit 0c5c270

I guess C.UTF-8 should be a better match, as it's supported since glibc 2.53 and should be more widely available.