opentable/otj-pg-embedded

Server start fails at `Gave up waiting for server to start after 10000m`

jiancoding opened this issue · 1 comments

Hi,
I got below error messages when running unit tests hitting embedded db:

2019-08-27 09:34:53,914 level=INFO [log:pid(1853)]init-3689ed5e-1d76-44f6-aeab-c5cf2df7da55:initdb requestId=[] callerId=[] - Success. You can now start the database server using:
2019-08-27 09:34:53,914 level=INFO [log:pid(1853)]init-3689ed5e-1d76-44f6-aeab-c5cf2df7da55:initdb requestId=[] callerId=[] -
2019-08-27 09:34:53,914 level=INFO [log:pid(1853)]init-3689ed5e-1d76-44f6-aeab-c5cf2df7da55:initdb requestId=[] callerId=[] - /var/folders/dn/37tjhb793bz1lr8j1r8cjj2w0000gp/T/embedded-pg/PG-3d7ce5d05cd575a649dd635576931b19/bin/pg_ctl -D /var/folders/dn/37tjhb793bz1lr8j1r8cjj2w0000gp/T/epg8770142186584571779 -l logfile start
2019-08-27 09:34:53,914 level=INFO [log:pid(1853)]init-3689ed5e-1d76-44f6-aeab-c5cf2df7da55:initdb requestId=[] callerId=[] -
2019-08-27 09:34:53,914 level=INFO [ScalaTest-run]com.opentable.db.postgres.embedded.EmbeddedPostgres requestId=[] callerId=[] - 3689ed5e-1d76-44f6-aeab-c5cf2df7da55 initdb completed in 00:00:01.625
2019-08-27 09:34:53,927 level=INFO [ScalaTest-run]com.opentable.db.postgres.embedded.EmbeddedPostgres requestId=[] callerId=[] - 3689ed5e-1d76-44f6-aeab-c5cf2df7da55 postmaster started as java.lang.UNIXProcess@2438dcd on port 49621. Waiting up to PT10S for server startup to finish.
2019-08-27 09:34:54,030 level=INFO [log:pid(1863)]pg-3689ed5e-1d76-44f6-aeab-c5cf2df7da55 requestId=[] callerId=[] - waiting for server to start....2019-08-27 09:34:54.029 CDT [1865] LOG: listening on IPv6 address "::1", port 49621
2019-08-27 09:34:54,030 level=INFO [log:pid(1863)]pg-3689ed5e-1d76-44f6-aeab-c5cf2df7da55 requestId=[] callerId=[] - 2019-08-27 09:34:54.030 CDT [1865] LOG: listening on Unix socket "/tmp/.s.PGSQL.49621"
2019-08-27 09:34:54,122 level=INFO [log:pid(1863)]pg-3689ed5e-1d76-44f6-aeab-c5cf2df7da55 requestId=[] callerId=[] - 2019-08-27 09:34:54.122 CDT [1866] LOG: database system was shut down at 2019-08-27 09:34:53 CDT
2019-08-27 09:34:54,127 level=INFO [log:pid(1863)]pg-3689ed5e-1d76-44f6-aeab-c5cf2df7da55 requestId=[] callerId=[] - 2019-08-27 09:34:54.127 CDT [1865] LOG: database system is ready to accept connections
2019-08-27 09:34:54,214 level=INFO [log:pid(1863)]pg-3689ed5e-1d76-44f6-aeab-c5cf2df7da55 requestId=[] callerId=[] - done
2019-08-27 09:34:54,214 level=INFO [log:pid(1863)]pg-3689ed5e-1d76-44f6-aeab-c5cf2df7da55 requestId=[] callerId=[] - server started

Exception encountered when invoking run on a nested suite - Failed to startup embedded database. Gave up waiting for server to start after 10000ms
org.scalatest.exceptions.TestFailedException: Failed to startup embedded database. Gave up waiting for server to start after 10000ms

at org.scalatest.Assertions$class.newAssertionFailedException(Assertions.scala:528)
at org.scalatest.FlatSpec.newAssertionFailedException(FlatSpec.scala:1685)
at org.scalatest.Assertions$class.fail(Assertions.scala:1089)
at org.scalatest.FlatSpec.fail(FlatSpec.scala:1685)
....

2019-08-27 09:35:04,061 level=INFO [log:pid(1863)]pg-3689ed5e-1d76-44f6-aeab-c5cf2df7da55 requestId=[] callerId=[] - 2019-08-27 09:35:04.061 CDT [1865] LOG: received fast shutdown request
2019-08-27 09:35:04,166 level=INFO [log:pid(1875)]init-3689ed5e-1d76-44f6-aeab-c5cf2df7da55:pg_ctl requestId=[] callerId=[] - waiting for server to shut down.... done
2019-08-27 09:35:04,166 level=INFO

I spent a lot time on this Java.IO exception, including clean up folder /var/folders/dn/37tjhb793bz1lr8j1r8cjj2w0000gp/T/embedded-pg/PG-3d7ce5d05cd575a649dd635576931b19/bin/pg_ctl, still no clue what's the problem. It seems that something is wrong with my local computer settings or maybe bad process leftover. Can you give me some hints?
Thanks

That's 100% not the library and rather the initdb process. Try downloading postgres and running it yourself to see what happens?