No internet connection
  1. Home
  2. Support

[install error] - PGSQL: too many clients already

By @jbtruffault
    2022-06-08 12:56:41.690Z

    Dear all !

    I'm trying to install talkyard by using docker-compose. So I used this example: https://github.com/debiki/talkyard-prod-one/blob/main/docker-compose.yml

    I set a password to my pgsql db, changed some settings in the file:

    At the end, when I launch the docker-compose up, app tries to connect many many times to the database, and finally the DB becomes full and not any other client can connect:

    500 Internal Server Error
    
    Talkyard's application server is trying to start, but cannot connect to the PostgreSQL database server [TyEDATABCONN1]
    
    
    debiki.Globals$DatabasePoolInitializationException: com.zaxxer.hikari.pool.HikariPool$PoolInitializationException: Failed to initialize pool: FATAL: sorry, too many clients already
    	at debiki.Globals.tryCreateStateUntilKilled(Globals.scala:923)
    	at debiki.Globals.$anonfun$startStuff$1(Globals.scala:842)
    	at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)
    	at scala.concurrent.Future$.$anonfun$apply$1(Future.scala:659)
    	at scala.util.Success.$anonfun$map$1(Try.scala:255)
    	at scala.util.Success.map(Try.scala:213)
    	at scala.concurrent.Future.$anonfun$map$1(Future.scala:292)
    	at scala.concurrent.impl.Promise.liftedTree1$1(Promise.scala:33)
    	at scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:33)
    	at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:64)
    	at akka.dispatch.BatchingExecutor$AbstractBatch.processBatch(BatchingExecutor.scala:63)
    	at akka.dispatch.BatchingExecutor$BlockableBatch.$anonfun$run$1(BatchingExecutor.scala:100)
    	at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)
    	at scala.concurrent.BlockContext$.withBlockContext(BlockContext.scala:85)
    	at akka.dispatch.BatchingExecutor$BlockableBatch.run(BatchingExecutor.scala:100)
    	at akka.dispatch.TaskInvocation.run(AbstractDispatcher.scala:49)
    	at akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(ForkJoinExecutorConfigurator.scala:48)
    	at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)
    	at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056)
    	at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)
    	at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)
    Caused by: com.zaxxer.hikari.pool.HikariPool$PoolInitializationException: Failed to initialize pool: FATAL: sorry, too many clients already
    	at com.zaxxer.hikari.pool.HikariPool.throwPoolInitializationException(HikariPool.java:596)
    	at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:582)
    	at com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:115)
    	at com.zaxxer.hikari.HikariDataSource.<init>(HikariDataSource.java:81)
    	at debiki.Debiki$.createPostgresHikariDataSource(Debiki.scala:129)
    	at debiki.Globals.tryCreateStateUntilKilled(Globals.scala:899)
    	... 20 more
    Caused by: org.postgresql.util.PSQLException: FATAL: sorry, too many clients already
    	at org.postgresql.Driver$ConnectThread.getResult(Driver.java:353)
    	at org.postgresql.Driver.connect(Driver.java:268)
    	at java.sql.DriverManager.getConnection(DriverManager.java:664)
    	at java.sql.DriverManager.getConnection(DriverManager.java:247)
    	at org.postgresql.ds.common.BaseDataSource.getConnection(BaseDataSource.java:103)
    	at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:364)
    	at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:206)
    	at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:476)
    	at com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:561)
    	... 24 more
    
    
    

    Does anyone already encountered this issue ?

    Regards !

    Solved in post #5, click to view
    • 12 replies

    There are 12 replies. Estimated reading time: 27 minutes

    1. I think this can happen if the application server (Play Framework) is using an old database password, but you've set a new database password.

      If you look in /opt/talkyard/conf/play-framework.conf, you see the correct database password?
      This line: talkyard.postgresql.password="...."
      If so, try restart the app server: docker-compose restart app.

      What if you send me the application server log files, in a private message, or and email?
      They're in /var/log/talkyard/talkyard-app.log (there might be some old files too: /var/log/talkyard/* ) Click my name to send a private message, or email support @ talkyard .io

      1. In reply tojbtruffault:

        Hmm, I realize that it'd be helpful if the app server remembered the very first database connection error,

        and then showed that error — because it's the interesting one, the "real" problem. Instead of showing the sorry, too many clients already error — which is not the real problem.

        (In the log files, though, we'd see the very first & real error.)

        1. J@jbtruffault
            2022-06-10 07:53:02.576Z2022-06-13 15:13:33.866Z

            Hi !
            First of all, thank you very much for taking time to answer !

            I had a look into the logs, here are the results:

                 1 {"message":"Starting... [TyMHELLO]","severity":"INFO"}
                 2 {"message":"Slf4jLogger started","severity":"INFO"}
                 3 {"message":"Initialized tracer=JaegerTracer(version=Java-0.35.5, serviceName=ty-app, reporter=RemoteReporter(sender=UdpSender(), closeEnqueueTimeout=1000), sampler=RemoteControlledSampler(maxOperations=2000, manager=HttpSampl       ingManager(hostPort=localhost:5778), sampler=ProbabilisticSampler(tags={sampler.type=probabilistic, sampler.param=0.001})), tags={hostname=7a7c5cc248aa, jaeger.version=Java-0.35.5, ip=192.168.10.161}, zipkinSharedRpcSpan=fals       e, expandExceptionLogs=false, useTraceId128Bit=false)","severity":"INFO"}
                 4 {"message":"Creating state.... [EdMCREATESTATE]","severity":"INFO"}
                 5 {"message":"Connecting to database... [EsM200CONNDB]","severity":"INFO"}
                 6 {"message":"Connecting to database: talkyard_rdb:5432/talkyard as user talkyard, read only","severity":"INFO"}
                 7 {"message":"HikariPool-1 - Starting...","severity":"INFO"}
                 8 {"message":"Started. [TyMSTARTED]","severity":"INFO"}
                 9 {"message":"Application started (Prod) (no global state)","severity":"INFO"}
                10 {"eventTime":"2022-06-08T12:44:56.574Z","message":"Using generated key with self signed certificate for HTTPS. This should NOT be used in production.","severity":"WARN","serviceContext":{"service":"talkyard-app","version":"v0       .2022.10.1"},"context":{"reportLocation":{"filePath":"DefaultSSLEngineProvider.scala","lineNumber":63,"functionName":"createSSLContext","className":"play.core.server.ssl.DefaultSSLEngineProvider"}}}
                11 {"eventTime":"2022-06-08T12:44:56.860Z","message":"HikariPool-1 - Exception during pool initialization.\norg.postgresql.util.PSQLException: The connection attempt failed.\n\tat org.postgresql.Driver$ConnectThread.getResult(Dr       iver.java:353)\n\tat org.postgresql.Driver.connect(Driver.java:268)\n\tat java.sql.DriverManager.getConnection(DriverManager.java:664)\n\tat java.sql.DriverManager.getConnection(DriverManager.java:247)\n\tat org.postgresql.ds       .common.BaseDataSource.getConnection(BaseDataSource.java:103)\n\tat com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:364)\n\tat com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:206)\n\tat com.zaxxer.hikar       i.pool.HikariPool.createPoolEntry(HikariPool.java:476)\n\tat com.zaxxer.hikari.pool.HikariPool.checkFailFast(HikariPool.java:561)\n\tat com.zaxxer.hikari.pool.HikariPool.<init>(HikariPool.java:115)\n\tat com.zaxxer.hikari.Hik       ariDataSource.<init>(HikariDataSource.java:81)\n\tat debiki.Debiki$.createPostgresHikariDataSource(Debiki.scala:129)\n\tat debiki.Globals.tryCreateStateUntilKilled(Globals.scala:899)\n\tat debiki.Globals.$anonfun$startStuff$1       (Globals.scala:842)\n\tat scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)\n\tat scala.concurrent.Future$.$anonfun$apply$1(Future.scala:659)\n\tat scala.util.Success.$anonfun$map$1(Try.scala:255)\n\tat s       cala.util.Success.map(Try.scala:213)\n\tat scala.concurrent.Future.$anonfun$map$1(Future.scala:292)\n\tat scala.concurrent.impl.Promise.liftedTree1$1(Promise.scala:33)\n\tat scala.concurrent.impl.Promise.$anonfun$transform$1(       Promise.scala:33)\n\tat scala.concurrent.impl.CallbackRunnable.run(Promise.scala:64)\n\tat akka.dispatch.BatchingExecutor$AbstractBatch.processBatch(BatchingExecutor.scala:63)\n\tat akka.dispatch.BatchingExecutor$BlockableBat       ch.$anonfun$run$1(BatchingExecutor.scala:100)\n\tat scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)\n\tat scala.concurrent.BlockContext$.withBlockContext(BlockContext.scala:85)\n\tat akka.dispatch.Batch       ingExecutor$BlockableBatch.run(BatchingExecutor.scala:100)\n\tat akka.dispatch.TaskInvocation.run(AbstractDispatcher.scala:49)\n\tat akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(ForkJoinExecutorConfigurato       r.scala:48)\n\tat java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)\n\tat java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056)\n\tat java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPoo       l.java:1692)\n\tat java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)\nCaused by: java.net.UnknownHostException: talkyard_rdb\n\tat java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.ja       va:184)\n\tat java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)\n\tat java.net.Socket.connect(Socket.java:589)\n\tat org.postgresql.core.PGStream.createSocket(PGStream.java:241)\n\tat org.postgresql.core.PGStream.<in       it>(PGStream.java:98)\n\tat org.postgresql.core.v3.ConnectionFactoryImpl.tryConnect(ConnectionFactoryImpl.java:109)\n\tat org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:235)\n\tat o       rg.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:49)\n\tat org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:223)\n\tat org.postgresql.Driver.makeConnection(Driver.java:402)\n\tat org.postgre       sql.Driver.access$100(Driver.java:60)\n\tat org.postgresql.Driver$ConnectThread.run(Driver.java:312)\n\tat java.lang.Thread.run(Thread.java:748)\n","severity":"ERROR","serviceContext":{"service":"talkyard-app","version":"v0.2       022.10.1"},"context":{"reportLocation":{"filePath":"HikariPool.java","lineNumber":594,"functionName":"throwPoolInitializationException","className":"com.zaxxer.hikari.pool.HikariPool"}}}
            
            ...
            
               152 {"message":"DB: trigger \"post_actions3_sum_quota\" for relation \"post_actions3\" does not exist, skipping","severity":"INFO"}
               153 {"message":"DB: trigger \"posts3_sum_quota\" for relation \"posts3\" does not exist, skipping","severity":"INFO"}
               154 {"message":"DB: trigger \"post_revs3_sum_quota\" for relation \"post_revisions3\" does not exist, skipping","severity":"INFO"}
               155 {"message":"Successfully applied 87 migrations to schema \"public\" (execution time 00:40.731s)","severity":"INFO"}
               156 {"message":"Done migrating database. Connecting to other services... [EsM200CONNOTR]","severity":"INFO"}
               157 {"message":"Connect to talkyard_cache/192.168.10.171:6379","severity":"INFO"}
               158 {"message":"Connected to talkyard_cache/192.168.10.171:6379","severity":"INFO"}
               159 {"eventTime":"2022-06-08T12:45:48.597Z","message":"Unknown state creation error [EsE4GY67]\njava.net.UnknownHostException: search: Name does not resolve\n\tat java.net.Inet4AddressImpl.lookupAllHostAddr(Native Method)\n\tat j       ava.net.InetAddress$2.lookupAllHostAddr(InetAddress.java:929)\n\tat java.net.InetAddress.getAddressesFromNameService(InetAddress.java:1324)\n\tat java.net.InetAddress.getAllByName0(InetAddress.java:1277)\n\tat java.net.InetAd       dress.getAllByName(InetAddress.java:1193)\n\tat java.net.InetAddress.getAllByName(InetAddress.java:1127)\n\tat java.net.InetAddress.getByName(InetAddress.java:1077)\n\tat debiki.Globals$State.<init>(Globals.scala:1140)\n\tat        debiki.Globals.tryCreateStateUntilKilled(Globals.scala:911)\n\tat debiki.Globals.$anonfun$startStuff$1(Globals.scala:842)\n\tat scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)\n\tat scala.concurrent.Fut       ure$.$anonfun$apply$1(Future.scala:659)\n\tat scala.util.Success.$anonfun$map$1(Try.scala:255)\n\tat scala.util.Success.map(Try.scala:213)\n\tat scala.concurrent.Future.$anonfun$map$1(Future.scala:292)\n\tat scala.concurrent.       impl.Promise.liftedTree1$1(Promise.scala:33)\n\tat scala.concurrent.impl.Promise.$anonfun$transform$1(Promise.scala:33)\n\tat scala.concurrent.impl.CallbackRunnable.run(Promise.scala:64)\n\tat akka.dispatch.BatchingExecutor$A       bstractBatch.processBatch(BatchingExecutor.scala:63)\n\tat akka.dispatch.BatchingExecutor$BlockableBatch.$anonfun$run$1(BatchingExecutor.scala:100)\n\tat scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)\       n\tat scala.concurrent.BlockContext$.withBlockContext(BlockContext.scala:85)\n\tat akka.dispatch.BatchingExecutor$BlockableBatch.run(BatchingExecutor.scala:100)\n\tat akka.dispatch.TaskInvocation.run(AbstractDispatcher.scala:       49)\n\tat akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(ForkJoinExecutorConfigurator.scala:48)\n\tat java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)\n\tat java.util.concurrent.ForkJoinPool$W       orkQueue.runTask(ForkJoinPool.java:1056)\n\tat java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)\n\tat java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)\n","severity":"ERROR","serv       iceContext":{"service":"talkyard-app","version":"v0.2022.10.1"},"context":{"reportLocation":{"filePath":"Globals.scala","lineNumber":931,"functionName":"tryCreateStateUntilKilled","className":"debiki.Globals"}}}
               160 {"message":"Connecting to database... [EsM200CONNDB]","severity":"INFO"}
               161 {"message":"Connecting to database: talkyard_rdb:5432/talkyard as user talkyard, read only","severity":"INFO"}
               162 {"message":"HikariPool-5 - Starting...","severity":"INFO"}
               163 {"message":"HikariPool-5 - Start completed.","severity":"INFO"}
               164 {"message":"Connected to database. [EsM2KP40]","severity":"INFO"}
               165 {"message":"Connecting to database: talkyard_rdb:5432/talkyard as user talkyard, read-write","severity":"INFO"}
               166 {"message":"HikariPool-6 - Starting...","severity":"INFO"}
               167 {"message":"HikariPool-6 - Start completed.","severity":"INFO"}
               168 {"message":"Connected to database. [EsM2KP40]","severity":"INFO"}
               169 {"message":"Running database migrations... [EsM200MIGRDB]","severity":"INFO"}
               170 {"message":"Database: jdbc:postgresql://talkyard_rdb:5432/talkyard (PostgreSQL 10.3)","severity":"INFO"}
               171 {"message":"Successfully validated 87 migrations (execution time 00:00.043s)","severity":"INFO"}
               172 {"message":"Current version of schema \"public\": 414","severity":"INFO"}
               173 {"message":"Schema \"public\" is up to date. No migration necessary.","severity":"INFO"}
               174 {"message":"Done migrating database. Connecting to other services... [EsM200CONNOTR]","severity":"INFO"}
               175 {"message":"Connect to talkyard_cache/192.168.10.171:6379","severity":"INFO"}
               176 {"message":"Connected to talkyard_cache/192.168.10.171:6379","severity":"INFO"}
            

            I have been first focused on the message Connecting to database: talkyard_rdb:5432/talkyard as user talkyard, read only, but I achieved to connect to the database with this user and to insert data with it. I guess it's not read only ..
            Indeed, by digging into the logs there is a message Connecting to database: talkyard_rdb:5432/talkyard as user talkyard, read-write.

            Now, I'm more worried about this message: java.net.UnknownHostException: search: Name does not resolve. This is the last message before a big number of Too many clients

            I hope you'll get an idea!

            Do not hesitate if you need more verbosity

            Regards

            1. Hmm it seems the hostnames of the services have been edited? For example, the database hostname is by default rdb but in the log messages there's: talkyard_rdb.

                "message": "HikariPool-1 - Exception during pool initialization.
                org.postgresql.util.PSQLException: The connection attempt failed.
                Caused by: java.net.UnknownHostException: talkyard_rdb   <——
              
                ...
                java.net.UnknownHostException: search: Name does not resolve
              

              The search engine runs in a container that's supposed to be named "search" — hmm, I see now that I've hardcoded that in the source:

              val elasticSearchHost = "search"

              but it seems to me you've renamed it to talkyard_search (just like talkyard_rdb) and then that name won't resolve (the ElasticSearch server won't be found).

              I think if you rename the search service back to search, it'll start working.

              ***

              And it'd be good if I could documented this better, and if there were more friendly error messages if a service is down or has the wrong hostname. ... And also if "search" could be renamed, wasn't hardcoded. Typically that doesn't matter though since they're in a separate Docker network not reachable from outside (except for Nginx, the web container / server).

              Reply1 LikeSolution
              1. J@jbtruffault
                  2022-06-11 13:57:23.884Z2022-06-11 14:04:57.507Z

                  Hey !

                  Indeed I renamed all the containers with talkyard_ prefix, just like you noticed: I run several docker containers on my server, it's usefull to have name that have an explicit mention of the service they are running.

                  I'll try to set the original names back and I tell you if something new happens !

                  1. J@jbtruffault
                      2022-06-11 14:16:05.578Z2022-06-11 15:54:33.631Z

                      Indeed ! I do not have the error any more ! Thank you a lot !

                      Next step in the installation: now I get a blank page with no error ! The page has the same favicon that this one, but nothing on it and no redirection...
                      I tried /admin /forum/latest and some others, everytime, I get "404 Not Found Page not found [TyE404_]"...

                      Here are the last logs, nothing appears when I reach the URL:

                      233 {"message":"Warming up Nashorn engine...","severity":"DEBUG"}
                      234 {"message":"Done rendering: 1327 ms, thread application-akka.actor.default-dispatcher-5  (id 20)","severity":"TRACE"}
                      235 {"message":"Warming up Nashorn engine, lap 1 done, took: 1327 ms","severity":"INFO"}
                      236 {"message":"Done rendering: 76 ms, thread application-akka.actor.default-dispatcher-5  (id 20)","severity":"TRACE"}
                      237 {"message":"Warming up Nashorn engine, lap 2 done, took: 76 ms","severity":"INFO"}
                      238 {"message":"Done rendering: 68 ms, thread application-akka.actor.default-dispatcher-5  (id 20)","severity":"TRACE"}
                      239 {"message":"Warming up Nashorn engine, lap 3 done, took: 68 ms","severity":"INFO"}
                      240 {"message":"Done warming up Nashorn engine, took: 1473 ms","severity":"INFO"}
                      241 {"message":"... Done creating 6 Javascript engines, async, took 35723 ms [EdMJSENGDONE]","severity":"INFO"}
                      242 {"message":"State created. [EsMSTATEREADY]","severity":"INFO"}
                      243 {"message":"s1: Mem cache: Inserting: SiteSettingsKey ","severity":"TRACE"}
                      244 {"message":"s1: Mem cache: Inserting: |SiteId ","severity":"TRACE"}
                      245 {"message":"s1: Mem cache: Inserting: Idps ","severity":"TRACE"}
                      246 {"message":"s1: Mem cache: Inserting: 10|PptById ","severity":"TRACE"}
                      247 {"message":"s1: Mem cache: Inserting: AllPemrs ","severity":"TRACE"}
                      248 {"message":"s1: Mem cache: Inserting: StrangersWatchbar ","severity":"TRACE"}
                      249 {"message":"Slf4jLogger started","severity":"INFO"}
                      250 {"message":"s1: Mem cache: Inserting: AllCats ","severity":"TRACE"}
                      251 {"message":"s1: Mem cache: Inserting: styles.css|AssetBundle ","severity":"TRACE"}
                      

                      Would you have any idea of where I should have a look to debug ?

                      1. J@jbtruffault
                          2022-06-14 07:52:32.548Z

                          @KajMagnus I'm sorry if I appear too insistent ... would you have any idea where does the blank page described above comes from ? If no, I can create a new topic: this one is not really relevant and I don't think that any one will dig into it !

                          Best regards !

                          1. Hi again, if the forum is online somewhere I can have a look? The address to the admin area is /-/admin (not /admin) and the forum homepage is, in your case, just / (or /latest), but not /forum/latest (that's just here at Ty .io).

                            (Sorry for the a bit late reply, many other things going on :- )   Those particular log messages look fine btw.)

                            1. Comment deleted
                              1. I think this config setting is missing in /opt/talkyard/conf/play-framework.conf:

                                talkyard.secure=true
                                

                                If that's instead false, Talkyard returns http: (not https) links to the scripts, and then the browsers won't run any scripts, won't show the page. Instead there're these errors in the browser log:

                                Blocked loading mixed active content “http://forum.oplgo.fr/-/assets/v0.2022.10.1/slim-bundle.min.js”
                                
                                1. J@jbtruffault
                                    2022-06-14 12:23:28.907Z

                                    Awesome ! It works !!!

                                    Thank you so much !

                                    1. Ok, I'm glad to hear :- )

                      2. In reply tojbtruffault:

                        About read/write and read-only: Talkyard creates different database connections, both read/write, and read-only — the latter only run queries against the database (but won't update any data), and they're used most of the time (so as not to accidentally change something when that wasn't supposed to happen).