yandex-qatools / postgresql-embedded

Embedded PostgreSQL Server
Other
493 stars 90 forks source link

Cached server path fails to find PID on Unix #142

Open mdoering opened 6 years ago

mdoering commented 6 years ago

I have used the embedded Postgres fine for a long time with the default temporary paths. When I tried to switch to a cached server path it worked fine on OSX. But when I deployed the code to a unix machine it hang on the second subsequent call with the same path argument and could not find the postmaster.pid. This happens on the Ubuntu 16, 18 and CentOS 7.5

I have created a small test class to demo the behavior: https://github.com/mdoering/pgembed-test

While debugging I noticed that the pid files created by the embedded postgres are kept in the bin folder of the postgres executables. The postmaster.pid file it is looking for when hanging is supposed to live in the data folder though. Is that expected?

mdoering commented 6 years ago
[vagrant@localhost pgtest]$ java -jar pgembed.jar 
154  [main] INFO  org.col.PgEmbedTest - Starting embedded Postgres 
157  [main] DEBUG org.col.PgEmbedTest - Use embedded Postgres, server dir=/tmp/pge-761456516187822187 
Extract /home/vagrant/.embedpostgresql/postgresql-10.3-1-linux-x64-binaries.tar.gz START
..............................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................Extract /home/vagrant/.embedpostgresql/postgresql-10.3-1-linux-x64-binaries.tar.gz DONE
2933 [main] DEBUG d.f.e.p.runtime.ProcessControl - Detected pid: 9934 
2939 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - The files belonging to this database system will be owned by user "vagrant".
This user must also own the server process.

The database cluster will be initialized with locale "C".
The default text search configuration will be set to "english".

Data page checksums are disabled.

fixing permissions on existing directory /tmp/postgresql-embed-d5dff248-48ce-4fd0-92ec-2a9b8ee4fc14/db-content-098fc9d2-c56d-4a61-b914-8b0b4c92b72a ... ok
creating subdirectories ... ok
selecting default max_connections ...  
2939 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - The files belonging to this database system will be owned by user "vagrant".

2939 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - This user must also own the server process.

2939 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

2939 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - The database cluster will be initialized with locale "C".

2940 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - The default text search configuration will be set to "english".

2940 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

2940 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - Data page checksums are disabled.

2940 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

2940 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - fixing permissions on existing directory /tmp/postgresql-embed-d5dff248-48ce-4fd0-92ec-2a9b8ee4fc14/db-content-098fc9d2-c56d-4a61-b914-8b0b4c92b72a ... ok

2940 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - creating subdirectories ... ok

2951 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 100
selecting default shared_buffers ...  
2951 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - selecting default max_connections ... 100

2966 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 128MB
selecting dynamic shared memory implementation ... posix
creating configuration files ...  
2966 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - selecting default shared_buffers ... 128MB

2966 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - selecting dynamic shared memory implementation ... posix

3069 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok
running bootstrap script ...  
3069 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - creating configuration files ... ok

3176 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok

3176 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - running bootstrap script ... ok

3176 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - performing post-bootstrap initialization ...  
3177 [main] INFO  d.f.e.process.runtime.Executable - start AbstractPostgresConfig{storage=Storage{dbDir=/tmp/postgresql-embed-d5dff248-48ce-4fd0-92ec-2a9b8ee4fc14/db-content-098fc9d2-c56d-4a61-b914-8b0b4c92b72a, dbName='abc', isTmpDir=true}, network=Net{host='localhost', port=44198}, timeout=Timeout{startupTimeout=15000}, credentials=Credentials{username='myname', password='letmein'}, args=[], additionalInitDbParams=[-E, SQL_ASCII, --locale=C, --lc-collate=C, --lc-ctype=C]} 
3602 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok
syncing data to disk ...  
3602 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok

3847 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok

Success. You can now start the database server using:

    /tmp/pge-761456516187822187/pgsql-10.3-1/pgsql/bin/pg_ctl -D /tmp/postgresql-embed-d5dff248-48ce-4fd0-92ec-2a9b8ee4fc14/db-content-098fc9d2-c56d-4a61-b914-8b0b4c92b72a -l logfile start

3847 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - syncing data to disk ... ok

3847 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

3847 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - Success. You can now start the database server using:

3847 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

3847 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor -     /tmp/pge-761456516187822187/pgsql-10.3-1/pgsql/bin/pg_ctl -D /tmp/postgresql-embed-d5dff248-48ce-4fd0-92ec-2a9b8ee4fc14/db-content-098fc9d2-c56d-4a61-b914-8b0b4c92b72a -l logfile start

3847 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

3850 [main] DEBUG d.f.e.p.runtime.ProcessControl - Detected pid: 9947 
3979 [main] DEBUG d.f.e.p.runtime.ProcessControl - Detected pid: 9955 
3980 [main] INFO  d.f.e.process.runtime.Executable - start AbstractPostgresConfig{storage=Storage{dbDir=/tmp/postgresql-embed-d5dff248-48ce-4fd0-92ec-2a9b8ee4fc14/db-content-098fc9d2-c56d-4a61-b914-8b0b4c92b72a, dbName='abc', isTmpDir=true}, network=Net{host='localhost', port=44198}, timeout=Timeout{startupTimeout=15000}, credentials=Credentials{username='myname', password='letmein'}, args=[abc], additionalInitDbParams=[]} 
5980 [main] INFO  d.f.e.process.runtime.Executable - start AbstractPostgresConfig{storage=Storage{dbDir=/tmp/postgresql-embed-d5dff248-48ce-4fd0-92ec-2a9b8ee4fc14/db-content-098fc9d2-c56d-4a61-b914-8b0b4c92b72a, dbName='abc', isTmpDir=true}, network=Net{host='localhost', port=44198}, timeout=Timeout{startupTimeout=15000}, credentials=Credentials{username='myname', password='letmein'}, args=[], additionalInitDbParams=[-E, SQL_ASCII, --locale=C, --lc-collate=C, --lc-ctype=C]} 
5986 [main] INFO  org.col.PgEmbedTest - Pg started on port 44198. Startup time: 5826 ms 
6073 [main] INFO  org.col.PgEmbedTest - Executed SQL successfully? true 
6074 [main] INFO  org.col.PgEmbedTest - Stopping embedded Postgres server=/tmp/pge-761456516187822187, data=/tmp/postgresql-embed-d5dff248-48ce-4fd0-92ec-2a9b8ee4fc14/db-content-098fc9d2-c56d-4a61-b914-8b0b4c92b72a 
6077 [main] INFO  r.y.q.e.postgresql.PostgresProcess - trying to stop postgresql 
6146 [main] DEBUG d.f.e.p.runtime.ProcessControl - Detected pid: 9962 
6147 [main] INFO  d.f.e.process.runtime.Executable - start AbstractPostgresConfig{storage=Storage{dbDir=/tmp/postgresql-embed-d5dff248-48ce-4fd0-92ec-2a9b8ee4fc14/db-content-098fc9d2-c56d-4a61-b914-8b0b4c92b72a, dbName='abc', isTmpDir=true}, network=Net{host='localhost', port=44198}, timeout=Timeout{startupTimeout=15000}, credentials=Credentials{username='myname', password='letmein'}, args=[stop], additionalInitDbParams=[]} 
6147 [Thread-5] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - waiting for server to shut down.... 
6248 [Thread-5] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor -  done
server stopped

6255 [main] DEBUG d.f.e.p.runtime.ProcessControl - Detected pid: 9965 

6266 [main] INFO  d.f.e.p.runtime.ProcessControl - execSuccess: false [kill, 9947] 
6358 [main] DEBUG d.f.embed.process.io.file.Files - could delete /tmp/postgresql-embed-d5dff248-48ce-4fd0-92ec-2a9b8ee4fc14/db-content-098fc9d2-c56d-4a61-b914-8b0b4c92b72a 
6359 [main] DEBUG d.f.embed.process.io.file.Files - could delete /tmp/pge-761456516187822187/pgsql-10.3-1/pgsql/bin/postgres.pid 
[vagrant@localhost pgtest]$ 
[vagrant@localhost pgtest]$ 
[vagrant@localhost pgtest]$ java -jar pgembed.jar 
145  [main] INFO  org.col.PgEmbedTest - Starting embedded Postgres 
147  [main] DEBUG org.col.PgEmbedTest - Use embedded Postgres, server dir=/tmp/pge-1447130410675650562 
Extract /home/vagrant/.embedpostgresql/postgresql-10.3-1-linux-x64-binaries.tar.gz START
..............................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................Extract /home/vagrant/.embedpostgresql/postgresql-10.3-1-linux-x64-binaries.tar.gz DONE
2879 [main] DEBUG d.f.e.p.runtime.ProcessControl - Detected pid: 9987 
2884 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - The files belonging to this database system will be owned by user "vagrant".
This user must also own the server process.

The database cluster will be initialized with locale "C".
The default text search configuration will be set to "english".

Data page checksums are disabled.

fixing permissions on existing directory /tmp/postgresql-embed-b45cecea-adef-4013-a686-8247732b6cba/db-content-051d0f05-1f0a-4b19-a763-e46c7c87a244 ... ok
creating subdirectories ... ok

2884 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - The files belonging to this database system will be owned by user "vagrant".

2884 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - This user must also own the server process.

2885 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

2885 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - The database cluster will be initialized with locale "C".

2885 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - The default text search configuration will be set to "english".

2885 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

2885 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - Data page checksums are disabled.

2885 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

2885 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - fixing permissions on existing directory /tmp/postgresql-embed-b45cecea-adef-4013-a686-8247732b6cba/db-content-051d0f05-1f0a-4b19-a763-e46c7c87a244 ... ok

2885 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - creating subdirectories ... ok

2885 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - selecting default max_connections ...  
2894 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 100
selecting default shared_buffers ...  
2894 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - selecting default max_connections ... 100

2916 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 128MB
selecting dynamic shared memory implementation ... posix
creating configuration files ...  
2916 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - selecting default shared_buffers ... 128MB

2916 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - selecting dynamic shared memory implementation ... posix

3002 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok
running bootstrap script ...  
3003 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - creating configuration files ... ok

3143 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok
performing post-bootstrap initialization ...  
3143 [main] INFO  d.f.e.process.runtime.Executable - start AbstractPostgresConfig{storage=Storage{dbDir=/tmp/postgresql-embed-b45cecea-adef-4013-a686-8247732b6cba/db-content-051d0f05-1f0a-4b19-a763-e46c7c87a244, dbName='abc', isTmpDir=true}, network=Net{host='localhost', port=39953}, timeout=Timeout{startupTimeout=15000}, credentials=Credentials{username='myname', password='letmein'}, args=[], additionalInitDbParams=[-E, SQL_ASCII, --locale=C, --lc-collate=C, --lc-ctype=C]} 
3595 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok
syncing data to disk ...  
3595 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - running bootstrap script ... ok

3829 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok

Success. You can now start the database server using:

    /tmp/pge-1447130410675650562/pgsql-10.3-1/pgsql/bin/pg_ctl -D /tmp/postgresql-embed-b45cecea-adef-4013-a686-8247732b6cba/db-content-051d0f05-1f0a-4b19-a763-e46c7c87a244 -l logfile start

3829 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - syncing data to disk ... ok

3829 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

3829 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - Success. You can now start the database server using:

3829 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

3829 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor -     /tmp/pge-1447130410675650562/pgsql-10.3-1/pgsql/bin/pg_ctl -D /tmp/postgresql-embed-b45cecea-adef-4013-a686-8247732b6cba/db-content-051d0f05-1f0a-4b19-a763-e46c7c87a244 -l logfile start

3829 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

3830 [main] DEBUG d.f.e.p.runtime.ProcessControl - Detected pid: 10000 
3979 [main] DEBUG d.f.e.p.runtime.ProcessControl - Detected pid: 10008 
3980 [main] INFO  d.f.e.process.runtime.Executable - start AbstractPostgresConfig{storage=Storage{dbDir=/tmp/postgresql-embed-b45cecea-adef-4013-a686-8247732b6cba/db-content-051d0f05-1f0a-4b19-a763-e46c7c87a244, dbName='abc', isTmpDir=true}, network=Net{host='localhost', port=39953}, timeout=Timeout{startupTimeout=15000}, credentials=Credentials{username='myname', password='letmein'}, args=[abc], additionalInitDbParams=[]} 
6024 [main] INFO  d.f.e.process.runtime.Executable - start AbstractPostgresConfig{storage=Storage{dbDir=/tmp/postgresql-embed-b45cecea-adef-4013-a686-8247732b6cba/db-content-051d0f05-1f0a-4b19-a763-e46c7c87a244, dbName='abc', isTmpDir=true}, network=Net{host='localhost', port=39953}, timeout=Timeout{startupTimeout=15000}, credentials=Credentials{username='myname', password='letmein'}, args=[], additionalInitDbParams=[-E, SQL_ASCII, --locale=C, --lc-collate=C, --lc-ctype=C]} 
6029 [main] INFO  org.col.PgEmbedTest - Pg started on port 39953. Startup time: 5880 ms 
6106 [main] INFO  org.col.PgEmbedTest - Executed SQL successfully? true 
6107 [main] INFO  org.col.PgEmbedTest - Stopping embedded Postgres server=/tmp/pge-1447130410675650562, data=/tmp/postgresql-embed-b45cecea-adef-4013-a686-8247732b6cba/db-content-051d0f05-1f0a-4b19-a763-e46c7c87a244 
6110 [main] INFO  r.y.q.e.postgresql.PostgresProcess - trying to stop postgresql 
6161 [main] DEBUG d.f.e.p.runtime.ProcessControl - Detected pid: 10015 
6162 [main] INFO  d.f.e.process.runtime.Executable - start AbstractPostgresConfig{storage=Storage{dbDir=/tmp/postgresql-embed-b45cecea-adef-4013-a686-8247732b6cba/db-content-051d0f05-1f0a-4b19-a763-e46c7c87a244, dbName='abc', isTmpDir=true}, network=Net{host='localhost', port=39953}, timeout=Timeout{startupTimeout=15000}, credentials=Credentials{username='myname', password='letmein'}, args=[stop], additionalInitDbParams=[]} 
6163 [Thread-5] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - waiting for server to shut down.... 
6263 [Thread-5] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor -  done
server stopped

6267 [main] DEBUG d.f.e.p.runtime.ProcessControl - Detected pid: 10018 

6279 [main] INFO  d.f.e.p.runtime.ProcessControl - execSuccess: false [kill, 10000] 
6348 [main] DEBUG d.f.embed.process.io.file.Files - could delete /tmp/postgresql-embed-b45cecea-adef-4013-a686-8247732b6cba/db-content-051d0f05-1f0a-4b19-a763-e46c7c87a244 
6348 [main] DEBUG d.f.embed.process.io.file.Files - could delete /tmp/pge-1447130410675650562/pgsql-10.3-1/pgsql/bin/postgres.pid 
[vagrant@localhost pgtest]$ java -jar pgembed.jar /tmp/pge
130  [main] INFO  org.col.PgEmbedTest - Starting embedded Postgres 
133  [main] DEBUG org.col.PgEmbedTest - Use embedded Postgres, server dir=/tmp/pge 
Extract /home/vagrant/.embedpostgresql/postgresql-10.3-1-linux-x64-binaries.tar.gz START
..............................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................Extract /home/vagrant/.embedpostgresql/postgresql-10.3-1-linux-x64-binaries.tar.gz DONE
2786 [main] DEBUG d.f.e.p.runtime.ProcessControl - Detected pid: 10040 
2791 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - The files belonging to this database system will be owned by user "vagrant".
This user must also own the server process.

The database cluster will be initialized with locale "C".
The default text search configuration will be set to "english".

Data page checksums are disabled.

fixing permissions on existing directory /tmp/postgresql-embed-99ffaa11-511f-4374-89ef-3908f446c0e2/db-content-84c0a460-9cd2-4c02-bf5a-7aff4a4bf9a3 ... ok
creating subdirectories ...  
2791 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - The files belonging to this database system will be owned by user "vagrant".

2792 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - This user must also own the server process.

2792 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

2792 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - The database cluster will be initialized with locale "C".

2792 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - The default text search configuration will be set to "english".

2792 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

2792 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - Data page checksums are disabled.

2792 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

2792 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - fixing permissions on existing directory /tmp/postgresql-embed-99ffaa11-511f-4374-89ef-3908f446c0e2/db-content-84c0a460-9cd2-4c02-bf5a-7aff4a4bf9a3 ... ok

2792 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok
selecting default max_connections ...  
2792 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - creating subdirectories ... ok

2810 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 100
selecting default shared_buffers ...  
2810 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - selecting default max_connections ... 100

2841 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 128MB
selecting dynamic shared memory implementation ... posix
creating configuration files ...  
2841 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - selecting default shared_buffers ... 128MB

2841 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - selecting dynamic shared memory implementation ... posix

2935 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok
running bootstrap script ...  
2935 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - creating configuration files ... ok

3077 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok
performing post-bootstrap initialization ...  
3077 [main] INFO  d.f.e.process.runtime.Executable - start AbstractPostgresConfig{storage=Storage{dbDir=/tmp/postgresql-embed-99ffaa11-511f-4374-89ef-3908f446c0e2/db-content-84c0a460-9cd2-4c02-bf5a-7aff4a4bf9a3, dbName='abc', isTmpDir=true}, network=Net{host='localhost', port=43109}, timeout=Timeout{startupTimeout=15000}, credentials=Credentials{username='myname', password='letmein'}, args=[], additionalInitDbParams=[-E, SQL_ASCII, --locale=C, --lc-collate=C, --lc-ctype=C]} 
3534 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok
syncing data to disk ...  
3534 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - running bootstrap script ... ok

3768 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok

Success. You can now start the database server using:

    /tmp/pge/pgsql-10.3-1/pgsql/bin/pg_ctl -D /tmp/postgresql-embed-99ffaa11-511f-4374-89ef-3908f446c0e2/db-content-84c0a460-9cd2-4c02-bf5a-7aff4a4bf9a3 -l logfile start

3768 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - syncing data to disk ... ok

3768 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

3768 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - Success. You can now start the database server using:

3768 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

3768 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor -     /tmp/pge/pgsql-10.3-1/pgsql/bin/pg_ctl -D /tmp/postgresql-embed-99ffaa11-511f-4374-89ef-3908f446c0e2/db-content-84c0a460-9cd2-4c02-bf5a-7aff4a4bf9a3 -l logfile start

3768 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

3769 [main] DEBUG d.f.e.p.runtime.ProcessControl - Detected pid: 10053 
3916 [main] DEBUG d.f.e.p.runtime.ProcessControl - Detected pid: 10061 
3917 [main] INFO  d.f.e.process.runtime.Executable - start AbstractPostgresConfig{storage=Storage{dbDir=/tmp/postgresql-embed-99ffaa11-511f-4374-89ef-3908f446c0e2/db-content-84c0a460-9cd2-4c02-bf5a-7aff4a4bf9a3, dbName='abc', isTmpDir=true}, network=Net{host='localhost', port=43109}, timeout=Timeout{startupTimeout=15000}, credentials=Credentials{username='myname', password='letmein'}, args=[abc], additionalInitDbParams=[]} 
5945 [main] INFO  d.f.e.process.runtime.Executable - start AbstractPostgresConfig{storage=Storage{dbDir=/tmp/postgresql-embed-99ffaa11-511f-4374-89ef-3908f446c0e2/db-content-84c0a460-9cd2-4c02-bf5a-7aff4a4bf9a3, dbName='abc', isTmpDir=true}, network=Net{host='localhost', port=43109}, timeout=Timeout{startupTimeout=15000}, credentials=Credentials{username='myname', password='letmein'}, args=[], additionalInitDbParams=[-E, SQL_ASCII, --locale=C, --lc-collate=C, --lc-ctype=C]} 
5950 [main] INFO  org.col.PgEmbedTest - Pg started on port 43109. Startup time: 5815 ms 
6029 [main] INFO  org.col.PgEmbedTest - Executed SQL successfully? true 
6031 [main] INFO  org.col.PgEmbedTest - Stopping embedded Postgres server=/tmp/pge, data=/tmp/postgresql-embed-99ffaa11-511f-4374-89ef-3908f446c0e2/db-content-84c0a460-9cd2-4c02-bf5a-7aff4a4bf9a3 
6034 [main] INFO  r.y.q.e.postgresql.PostgresProcess - trying to stop postgresql 
6058 [main] DEBUG d.f.e.p.runtime.ProcessControl - Detected pid: 10068 
6059 [Thread-5] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - waiting for server to shut down.... 
6059 [main] INFO  d.f.e.process.runtime.Executable - start AbstractPostgresConfig{storage=Storage{dbDir=/tmp/postgresql-embed-99ffaa11-511f-4374-89ef-3908f446c0e2/db-content-84c0a460-9cd2-4c02-bf5a-7aff4a4bf9a3, dbName='abc', isTmpDir=true}, network=Net{host='localhost', port=43109}, timeout=Timeout{startupTimeout=15000}, credentials=Credentials{username='myname', password='letmein'}, args=[stop], additionalInitDbParams=[]} 
6159 [Thread-5] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor -  done
server stopped

6164 [main] DEBUG d.f.e.p.runtime.ProcessControl - Detected pid: 10071 

6177 [main] INFO  d.f.e.p.runtime.ProcessControl - execSuccess: false [kill, 10053] 
6247 [main] DEBUG d.f.embed.process.io.file.Files - could delete /tmp/postgresql-embed-99ffaa11-511f-4374-89ef-3908f446c0e2/db-content-84c0a460-9cd2-4c02-bf5a-7aff4a4bf9a3 
6248 [main] DEBUG d.f.embed.process.io.file.Files - could delete /tmp/pge/pgsql-10.3-1/pgsql/bin/postgres.pid 
[vagrant@localhost pgtest]$ 
[vagrant@localhost pgtest]$ 
[vagrant@localhost pgtest]$ 
[vagrant@localhost pgtest]$ java -jar pgembed.jar /tmp/pge
138  [main] INFO  org.col.PgEmbedTest - Starting embedded Postgres 
140  [main] DEBUG org.col.PgEmbedTest - Use embedded Postgres, server dir=/tmp/pge 
321  [main] DEBUG d.f.e.p.runtime.ProcessControl - Detected pid: 10093 
324  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - The files belonging to this database system will be owned by user "vagrant".
This user must also own the server process.

The database cluster will be initialized with locale "C".
The default text search configuration will be set to "english".

Data page checksums are disabled.

fixing permissions on existing directory /tmp/postgresql-embed-145b7bc1-7dfa-4ee8-bde9-e5a01407080f/db-content-2f441082-f03e-4bd4-98a9-0877c7ac8593 ... ok

324  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - The files belonging to this database system will be owned by user "vagrant".

325  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - This user must also own the server process.

325  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

325  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - The database cluster will be initialized with locale "C".

325  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - The default text search configuration will be set to "english".

325  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

325  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - Data page checksums are disabled.

325  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

325  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - fixing permissions on existing directory /tmp/postgresql-embed-145b7bc1-7dfa-4ee8-bde9-e5a01407080f/db-content-2f441082-f03e-4bd4-98a9-0877c7ac8593 ... ok

326  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - creating subdirectories ...  
342  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok
selecting default max_connections ...  
342  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - creating subdirectories ... ok

352  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 100
selecting default shared_buffers ...  
352  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - selecting default max_connections ... 100

366  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 128MB
selecting dynamic shared memory implementation ...  
366  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - selecting default shared_buffers ... 128MB

366  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - posix
creating configuration files ...  
366  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - selecting dynamic shared memory implementation ... posix

453  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok
running bootstrap script ...  
453  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - creating configuration files ... ok

549  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok

549  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - running bootstrap script ... ok

549  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - performing post-bootstrap initialization ...  
549  [main] INFO  d.f.e.process.runtime.Executable - start AbstractPostgresConfig{storage=Storage{dbDir=/tmp/postgresql-embed-145b7bc1-7dfa-4ee8-bde9-e5a01407080f/db-content-2f441082-f03e-4bd4-98a9-0877c7ac8593, dbName='abc', isTmpDir=true}, network=Net{host='localhost', port=37957}, timeout=Timeout{startupTimeout=15000}, credentials=Credentials{username='myname', password='letmein'}, args=[], additionalInitDbParams=[-E, SQL_ASCII, --locale=C, --lc-collate=C, --lc-ctype=C]} 
952  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok
syncing data to disk ...  
952  [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok

1175 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - ok

Success. You can now start the database server using:

    /tmp/pge/pgsql-10.3-1/pgsql/bin/pg_ctl -D /tmp/postgresql-embed-145b7bc1-7dfa-4ee8-bde9-e5a01407080f/db-content-2f441082-f03e-4bd4-98a9-0877c7ac8593 -l logfile start

1175 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - syncing data to disk ... ok

1175 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

1175 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - Success. You can now start the database server using:

1175 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

1175 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor -     /tmp/pge/pgsql-10.3-1/pgsql/bin/pg_ctl -D /tmp/postgresql-embed-145b7bc1-7dfa-4ee8-bde9-e5a01407080f/db-content-2f441082-f03e-4bd4-98a9-0877c7ac8593 -l logfile start

1176 [Thread-1] DEBUG r.y.q.e.p.e.LogWatchStreamProcessor - 

1177 [main] DEBUG d.f.e.p.runtime.ProcessControl - Detected pid: 10106 
22319 [main] ERROR r.y.q.e.postgresql.PostgresProcess - Failed to read PID file (File '/tmp/postgresql-embed-145b7bc1-7dfa-4ee8-bde9-e5a01407080f/db-content-2f441082-f03e-4bd4-98a9-0877c7ac8593/postmaster.pid' does not exist) 
java.io.FileNotFoundException: File '/tmp/postgresql-embed-145b7bc1-7dfa-4ee8-bde9-e5a01407080f/db-content-2f441082-f03e-4bd4-98a9-0877c7ac8593/postmaster.pid' does not exist
    at org.apache.commons.io.FileUtils.openInputStream(FileUtils.java:299)
    at org.apache.commons.io.FileUtils.readLines(FileUtils.java:1783)
    at org.apache.commons.io.FileUtils.readLines(FileUtils.java:1819)
    at ru.yandex.qatools.embed.postgresql.PostgresProcess.onAfterProcessStart(PostgresProcess.java:255)
    at de.flapdoodle.embed.process.runtime.AbstractProcess.<init>(AbstractProcess.java:116)
    at ru.yandex.qatools.embed.postgresql.AbstractPGProcess.<init>(AbstractPGProcess.java:19)
    at ru.yandex.qatools.embed.postgresql.PostgresProcess.<init>(PostgresProcess.java:68)
    at ru.yandex.qatools.embed.postgresql.PostgresExecutable.start(PostgresExecutable.java:25)
    at ru.yandex.qatools.embed.postgresql.PostgresExecutable.start(PostgresExecutable.java:13)
    at de.flapdoodle.embed.process.runtime.Executable.start(Executable.java:108)
    at ru.yandex.qatools.embed.postgresql.EmbeddedPostgres.start(EmbeddedPostgres.java:173)
    at org.col.PgEmbedTest.start(PgEmbedTest.java:66)
    at org.col.PgEmbedTest.main(PgEmbedTest.java:101)
22343 [main] DEBUG d.f.e.p.runtime.ProcessControl - Detected pid: 10107 
22344 [main] INFO  d.f.e.process.runtime.Executable - start AbstractPostgresConfig{storage=Storage{dbDir=/tmp/postgresql-embed-145b7bc1-7dfa-4ee8-bde9-e5a01407080f/db-content-2f441082-f03e-4bd4-98a9-0877c7ac8593, dbName='abc', isTmpDir=true}, network=Net{host='localhost', port=37957}, timeout=Timeout{startupTimeout=15000}, credentials=Credentials{username='myname', password='letmein'}, args=[abc], additionalInitDbParams=[]} 
^C114464 [main] INFO  d.f.e.process.runtime.Executable - start AbstractPostgresConfig{storage=Storage{dbDir=/tmp/postgresql-embed-145b7bc1-7dfa-4ee8-bde9-e5a01407080f/db-content-2f441082-f03e-4bd4-98a9-0877c7ac8593, dbName='abc', isTmpDir=true}, network=Net{host='localhost', port=37957}, timeout=Timeout{startupTimeout=15000}, credentials=Credentials{username='myname', password='letmein'}, args=[], additionalInitDbParams=[-E, SQL_ASCII, --locale=C, --lc-collate=C, --lc-ctype=C]} 
miwroblewski commented 6 years ago

I do have the same issue. Did you guys found some workaround? Or the only option is to create pull request with fix?

mdoering commented 6 years ago

No I didn't. Tried to use the System setting de.flapdoodle.embed.io.tmpdir but it's the same problem. We ended up not using a cached directory.

chriskilding commented 5 years ago

We have just found the same issue in our setup. Caching the Postgres directory worked fine on our Macs (Sierra and High Sierra) but failed when we pushed our project to Jenkins (running Debian). Turning off the cache fixed it for us. (Obviously this isn’t ideal... but it works for now.)

heruan commented 5 years ago

I'm getting the same error also without the cache, i.e.

new EmbeddedPostgres(Version.V10_3).start(
        EmbeddedPostgres.defaultRuntimeConfig(), "127.0.0.1", 5432,
        "boot", "boot", "boot", Collections.emptyList());
java.io.FileNotFoundException: File '/var/folders/p5/5hdkd1xs4qg82tb6g1_rk35crmp1p9/T/postgresql-embed-53b768ec-9422-44f5-b30f-e87dadb5c994/db-content-c39d3c7f-7b88-4c90-9c16-69537641005d/postmaster.pid' does not exist
    at org.apache.commons.io.FileUtils.openInputStream(FileUtils.java:292) ~[commons-io-2.5.jar:2.5]
    at org.apache.commons.io.FileUtils.readLines(FileUtils.java:1835) ~[commons-io-2.5.jar:2.5]
    at org.apache.commons.io.FileUtils.readLines(FileUtils.java:1869) ~[commons-io-2.5.jar:2.5]
    at ru.yandex.qatools.embed.postgresql.PostgresProcess.onAfterProcessStart(PostgresProcess.java:255) [postgresql-embedded-2.9.jar:na]
    at de.flapdoodle.embed.process.runtime.AbstractProcess.<init>(AbstractProcess.java:116) [de.flapdoodle.embed.process-2.0.3.jar:na]
    at ru.yandex.qatools.embed.postgresql.AbstractPGProcess.<init>(AbstractPGProcess.java:19) [postgresql-embedded-2.9.jar:na]
    at ru.yandex.qatools.embed.postgresql.PostgresProcess.<init>(PostgresProcess.java:68) [postgresql-embedded-2.9.jar:na]
    at ru.yandex.qatools.embed.postgresql.PostgresExecutable.start(PostgresExecutable.java:25) [postgresql-embedded-2.9.jar:na]
    at ru.yandex.qatools.embed.postgresql.PostgresExecutable.start(PostgresExecutable.java:13) [postgresql-embedded-2.9.jar:na]
    at de.flapdoodle.embed.process.runtime.Executable.start(Executable.java:108) [de.flapdoodle.embed.process-2.0.3.jar:na]
    at ru.yandex.qatools.embed.postgresql.EmbeddedPostgres.start(EmbeddedPostgres.java:173) [postgresql-embedded-2.9.jar:na]
Krigu commented 5 years ago

I have the same issue with / without cache on an Ubuntu

hopkinsjason commented 5 years ago

I've noticed this issue, but I found it to be a postgres process that had been left running.

You can validate this by either looking for the process issuing this command in linux:

ps -ax | grep postgres

Or try and find the running pid file in the same general area as the one that had been reported missing. For example (using your error above):

cd /var/folders/p5/5hdkd1xs4qg82tb6g1_rk35crmp1p9/T/
find . -name postmaster.pid

if you get a result not in the directory that's reported in the exception, then you have a rouge process.

glickid commented 5 years ago

Having the same issue, is there a solution?

java.io.FileNotFoundException: File '/tmp/postgresql-embed-d42a05e0-390c-47ff-ae4f-eb9a16909b83/db-content-cecf683a-033b-4b22-9393-db2dd7f798d4/postmaster.pid' does not exist [17:10:37] at org.apache.commons.io.FileUtils.openInputStream(FileUtils.java:299) [17:10:37] at org.apache.commons.io.FileUtils.readLines(FileUtils.java:1783) [17:10:37] at org.apache.commons.io.FileUtils.readLines(FileUtils.java:1819) [17:10:37] at ru.yandex.qatools.embed.postgresql.PostgresProcess.onAfterProcessStart(PostgresProcess.java:256) [17:10:37] at de.flapdoodle.embed.process.runtime.AbstractProcess.(AbstractProcess.java:116) [17:10:37] at ru.yandex.qatools.embed.postgresql.AbstractPGProcess.(AbstractPGProcess.java:19) [17:10:37] at ru.yandex.qatools.embed.postgresql.PostgresProcess.(PostgresProcess.java:68) [17:10:37] at ru.yandex.qatools.embed.postgresql.PostgresExecutable.start(PostgresExecutable.java:25) [17:10:37] at ru.yandex.qatools.embed.postgresql.PostgresExecutable.start(PostgresExecutable.java:13) [17:10:37] at de.flapdoodle.embed.process.runtime.Executable.start(Executable.java:108) [17:10:37] at ru.yandex.qatools.embed.postgresql.EmbeddedPostgres.start(EmbeddedPostgres.java:194) [17:10:37] at ru.yandex.qatools.embed.postgresql.EmbeddedPostgres.start(EmbeddedPostgres.java:165) [17:10:37] at ru.yandex.qatools.embed.postgresql.EmbeddedPostgres.start(EmbeddedPostgres.java:139)

SButterfly commented 4 years ago

The same error...