Uploaded image for project: 'PuppetDB'
  1. PuppetDB
  2. PDB-4401

puppetdb : Error while attempting to create connection pool

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Normal
    • Resolution: Cannot Reproduce
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: PuppetDB
    • Labels:
      None
    • Template:
    • Master Config:
      Split
    • Agent OS:
      Other
    • Master OS:
      Other
    • Affects Build:
      7.2.0
    • Method Found:
      Needs Assessment
    • QA Risk Assessment:
      Needs Assessment

      Description

      working with the version that I uploaded from forge https://github.com/puppetlabs/puppetlabs-puppetdb/tree/7.2.0
      puppet-agent 5.5.8 - working on Ubuntu 18.04.
      puppet-server version: 5.3.6 - working on Ubuntu 18.04.

      my puppet-run seems completely stuck applying the puppetdb recipes.
      someone could guide me for next steps. I am stuck.

      here the message log on puppetdb:
      The connection is not available - Caused by: org.postgresql.util.PSQLException: Connection to puppetdb.internet.net:5432 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.

      • here my puppetdb definition on manifest:

        class profile::puppetdb {
         
          class { '::puppetdb::database::postgresql' :
            listen_addresses    => $::fqdn,
            manage_package_repo => false,
            postgres_version    => '9.6',
          }
          class { '::puppetdb::server' :
            database_host         => $::fqdn,
            automatic_dlo_cleanup => false,
            manage_firewall       => false,
            listen_address        => '0.0.0.0',
            ssl_deploy_certs      => true,
            ssl_set_cert_paths    => true,
            java_args             => {
              '-Xmx' => '2g',
              '-Xms' => '512m',
            },
          }
        }

      • here the last puppet-run (without errrors...)

        Notice: /Stage[main]/Postgresql::Server::Install/Package[postgresql-server]/ensure: created
        Notice: /Stage[main]/Puppetdb::Server/Package[puppetdb]/ensure: created
        Info: /Stage[main]/Puppetdb::Server/Package[puppetdb]: Scheduling refresh of Service[puppetdb]
        Notice: /Stage[main]/Puppetdb::Server::Global/File[/etc/puppetlabs/puppetdb/conf.d/config.ini]/owner: owner changed 'root' to 'puppetdb'
        Notice: /Stage[main]/Puppetdb::Server::Global/File[/etc/puppetlabs/puppetdb/conf.d/config.ini]/group: group changed 'root' to 'puppetdb'
        Notice: /Stage[main]/Puppetdb::Server::Global/File[/etc/puppetlabs/puppetdb/conf.d/config.ini]/mode: mode changed '0644' to '0600'
        Info: Class[Puppetdb::Server::Global]: Scheduling refresh of Service[puppetdb]
        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]/group: group changed 'root' to 'puppetdb'
        Notice: /Stage[main]/Puppetdb::Server::Database/File[/etc/puppetlabs/puppetdb/conf.d/database.ini]/mode: mode changed '0644' to '0600'
        Notice: /Stage[main]/Puppetdb::Server::Database/Ini_setting[puppetdb_psdatabase_username]/ensure: created
        Notice: /Stage[main]/Puppetdb::Server::Database/Ini_setting[puppetdb_psdatabase_password]/ensure: created
        Notice: /Stage[main]/Puppetdb::Server::Database/Ini_setting[puppetdb_classname]/ensure: created
        Notice: /Stage[main]/Puppetdb::Server::Database/Ini_setting[puppetdb_subprotocol]/ensure: created
        Notice: /Stage[main]/Puppetdb::Server::Database/Ini_setting[puppetdb_pgs]/ensure: created
        Notice: /Stage[main]/Puppetdb::Server::Database/Ini_setting[puppetdb_subname]/ensure: created
        Notice: /Stage[main]/Puppetdb::Server::Database/Ini_setting[puppetdb_gc_interval]/ensure: created
        Notice: /Stage[main]/Puppetdb::Server::Database/Ini_setting[puppetdb_node_ttl]/ensure: created
        Notice: /Stage[main]/Puppetdb::Server::Database/Ini_setting[puppetdb_node_purge_ttl]/ensure: created
        Notice: /Stage[main]/Puppetdb::Server::Database/Ini_setting[puppetdb_report_ttl]/ensure: created
        Notice: /Stage[main]/Puppetdb::Server::Database/Ini_setting[puppetdb_conn_max_age]/ensure: created
        Notice: /Stage[main]/Puppetdb::Server::Database/Ini_setting[puppetdb_conn_keep_alive]/ensure: created
        Notice: /Stage[main]/Puppetdb::Server::Database/Ini_setting[puppetdb_conn_lifetime]/ensure: created
        Info: Class[Puppetdb::Server::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]/group: group changed 'root' to 'puppetdb'
        Notice: /Stage[main]/Puppetdb::Server::Jetty/File[/etc/puppetlabs/puppetdb/conf.d/jetty.ini]/mode: mode changed '0644' to '0600'
        Notice: /Stage[main]/Puppetdb::Server::Jetty/Ini_setting[puppetdb_host]/ensure: created
        Info: Class[Puppetdb::Server::Jetty]: Scheduling refresh of Service[puppetdb]
        Notice: /Stage[main]/Puppetdb::Server::Puppetdb/File[/etc/puppetlabs/puppetdb/conf.d/puppetdb.ini]/ensure: created
        Info: Class[Puppetdb::Server::Puppetdb]: Scheduling refresh of Service[puppetdb]
        Notice: /Stage[main]/Puppetdb::Server/Ini_subsetting['-Xmx']/value: value changed '192m' to '2g'
        Info: /Stage[main]/Puppetdb::Server/Ini_subsetting['-Xmx']: Scheduling refresh of Service[puppetdb]
        Notice: /Stage[main]/Puppetdb::Server/Ini_subsetting['-Xms']/ensure: created
        Info: /Stage[main]/Puppetdb::Server/Ini_subsetting['-Xms']: Scheduling refresh of Service[puppetdb]
        

      • here the puppetdb.log

        2019-06-13 09:01:41,886 WARN  [c.z.h.HikariConfig] The initializationFailFast propery is deprecated, see initializationFailTimeout
        2019-06-13 09:01:41,886 INFO  [c.z.h.HikariDataSource] PDBMigrationsPool - Starting...
        2019-06-13 09:01:41,890 INFO  [c.z.h.HikariDataSource] PDBMigrationsPool - Start completed.
        2019-06-13 09:01:56,891 INFO  [c.z.h.HikariDataSource] PDBMigrationsPool - Shutdown initiated...
        2019-06-13 09:02:00,599 INFO  [c.z.h.HikariDataSource] PDBMigrationsPool - Shutdown completed.
        2019-06-13 09:02:00,601 ERROR [p.p.c.services] Error while attempting to create connection pool
        java.sql.SQLTransientConnectionException: PDBMigrationsPool - Connection is not available, request timed out after 15000ms.
                at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:602)
                at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:195)
                at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:145)
                at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:85)
                at clojure.java.jdbc$get_connection.invokeStatic(jdbc.clj:307)
                at clojure.java.jdbc$get_connection.invoke(jdbc.clj:197)
                at puppetlabs.puppetdb.cli.services$initialize_schema.invokeStatic(services.clj:318)
                at puppetlabs.puppetdb.cli.services$initialize_schema.invoke(services.clj:312)
                at puppetlabs.puppetdb.cli.services$init_with_db$fn__41128.invoke(services.clj:351)
                at puppetlabs.puppetdb.cli.services$init_with_db.invokeStatic(services.clj:347)
                at puppetlabs.puppetdb.cli.services$init_with_db.invoke(services.clj:331)
                at puppetlabs.puppetdb.cli.services$start_puppetdb.invokeStatic(services.clj:421)
                at puppetlabs.puppetdb.cli.services$start_puppetdb.invoke(services.clj:399)
                at puppetlabs.puppetdb.cli.services$reify__41242$service_fnk__13694__auto___positional$reify__41253.start(services.clj:509)
                at puppetlabs.trapperkeeper.services$eval13496$fn__13510$G__13486__13513.invoke(services.clj:9)
                at puppetlabs.trapperkeeper.services$eval13496$fn__13510$G__13485__13517.invoke(services.clj:9)
                at puppetlabs.trapperkeeper.internal$eval26140$run_lifecycle_fn_BANG___26147$fn__26148.invoke(internal.clj:198)
                at puppetlabs.trapperkeeper.internal$eval26140$run_lifecycle_fn_BANG___26147.invoke(internal.clj:181)
                at puppetlabs.trapperkeeper.internal$eval26169$run_lifecycle_fns__26174$fn__26175.invoke(internal.clj:231)
                at puppetlabs.trapperkeeper.internal$eval26169$run_lifecycle_fns__26174.invoke(internal.clj:208)
                at puppetlabs.trapperkeeper.internal$eval26651$build_app_STAR___26660$fn$reify__26670.start(internal.clj:586)
                at puppetlabs.trapperkeeper.internal$eval26697$boot_services_for_app_STAR__STAR___26704$fn__26705$fn__26707.invoke(internal.clj:612)
                at puppetlabs.trapperkeeper.internal$eval26697$boot_services_for_app_STAR__STAR___26704$fn__26705.invoke(internal.clj:610)
                at puppetlabs.trapperkeeper.internal$eval26697$boot_services_for_app_STAR__STAR___26704.invoke(internal.clj:604)
                at clojure.core$partial$fn__4761.invoke(core.clj:2521)
                at puppetlabs.trapperkeeper.internal$eval26210$initialize_lifecycle_worker__26221$fn__26222$fn__26318$state_machine__18315__auto____26319$fn__26321.invoke(internal.clj:251)
                at puppetlabs.trapperkeeper.internal$eval26210$initialize_lifecycle_worker__26221$fn__26222$fn__26318$state_machine__18315__auto____26319.invoke(internal.clj:251)
                at clojure.core.async.impl.ioc_macros$run_state_machine.invokeStatic(ioc_macros.clj:1012)
                at clojure.core.async.impl.ioc_macros$run_state_machine.invoke(ioc_macros.clj:1011)
                at clojure.core.async.impl.ioc_macros$run_state_machine_wrapped.invokeStatic(ioc_macros.clj:1016)
                at clojure.core.async.impl.ioc_macros$run_state_machine_wrapped.invoke(ioc_macros.clj:1014)
                at clojure.core.async$ioc_alts_BANG_$fn__18483.invoke(async.clj:383)
                at clojure.core.async$do_alts$fn__18429$fn__18432.invoke(async.clj:252)
                at clojure.core.async.impl.channels.ManyToManyChannel$fn__17041$fn__17042.invoke(channels.clj:95)
                at clojure.lang.AFn.run(AFn.java:22)
                at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1135)
                at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
                at java.base/java.lang.Thread.run(Thread.java:844)
        Caused by: org.postgresql.util.PSQLException: Connection to puppetdb.internet.net:5432 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.
                at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:252)
                at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:66)
                at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:215)
                at org.postgresql.Driver.makeConnection(Driver.java:406)
                at org.postgresql.Driver.connect(Driver.java:274)
                at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:95)
                at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:101)
                at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:356)
                at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:199)
                at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:444)
                at com.zaxxer.hikari.pool.HikariPool.access$200(HikariPool.java:71)
                at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:631)
                at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:617)
                at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
                ... 3 common frames omitted
        Caused by: java.net.ConnectException: Connection refused (Connection refused)
                at java.base/java.net.PlainSocketImpl.socketConnect(Native Method)
                at java.base/java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:400)
                at java.base/java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:243)
                at java.base/java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:225)
                at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:402)
                at java.base/java.net.Socket.connect(Socket.java:591)
                at org.postgresql.core.PGStream.<init>(PGStream.java:64)
                at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:133)
                ... 16 common frames omitted
        

      • here network open connection log

        # netstat -tulnp|grep postgres
        tcp        0      0 127.0.0.1:5432          0.0.0.0:*               LISTEN      14226/postgres
        tcp6       0      0 ::1:5432                :::*                    LISTEN      14226/postgres
        

      • here postgres log

        root@01:~# cat /var/log/postgresql/postgresql-9.6-main.log
        2019-06-13 08:59:10.708 UTC [14236] LOG:  database system was shut down at 2019-06-13 08:59:09 UTC
        2019-06-13 08:59:10.709 UTC [14236] LOG:  MultiXact member wraparound protections are now enabled
        2019-06-13 08:59:10.712 UTC [14226] LOG:  database system is ready to accept connections
        2019-06-13 08:59:10.713 UTC [14241] LOG:  autovacuum launcher started
        2019-06-13 08:59:11.177 UTC [14244] [unknown]@[unknown] LOG:  incomplete startup packet
        

      • here the Postgres config

        grep -o '^[^#]*'  /etc/postgresql/9.6/main/postgresql.conf|sort
         
        cluster_name = '9.6/main'
        data_directory = '/var/lib/postgresql/9.6/main'
        datestyle = 'iso, mdy'
        default_text_search_config = 'pg_catalog.english'
        dynamic_shared_memory_type = posix
        external_pid_file = '/var/run/postgresql/9.6-main.pid'
        hba_file = '/etc/postgresql/9.6/main/pg_hba.conf'
        ident_file = '/etc/postgresql/9.6/main/pg_ident.conf'
        include_dir = 'conf.d'
        lc_messages = 'en_US.UTF-8'
        lc_monetary = 'en_US.UTF-8'
        lc_numeric = 'en_US.UTF-8'
        lc_time = 'en_US.UTF-8'
        listen_addresses = 'puppetdb.internet.net'
        log_line_prefix = '%m [%p] %q%u@%d '
        log_timezone = UTC
        max_connections = 100
        port = 5432
        shared_buffers = 128MB
        ssl_cert_file = '/etc/ssl/certs/ssl-cert-snakeoil.pem'
        ssl_key_file = '/etc/ssl/private/ssl-cert-snakeoil.key'
        ssl = on
        stats_temp_directory = '/var/run/postgresql/9.6-main.pg_stat_tmp'
        timezone = UTC
        unix_socket_directories = '/var/run/postgresql'
        

        Attachments

          Activity

            People

            • Assignee:
              Unassigned
              Reporter:
              tutelacooldouce zoen
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Zendesk Support