Skip to content
This repository has been archived by the owner on May 12, 2020. It is now read-only.

Cached server path fails to find PID on Unix #142

Open
mdoering opened this issue Sep 4, 2018 · 9 comments
Open

Cached server path fails to find PID on Unix #142

mdoering opened this issue Sep 4, 2018 · 9 comments

Comments

@mdoering
Copy link

mdoering commented Sep 4, 2018

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
Copy link
Author

mdoering commented Sep 4, 2018

[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
Copy link

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

@mdoering
Copy link
Author

mdoering commented Sep 9, 2018

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
Copy link

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
Copy link

heruan commented Sep 22, 2018

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
Copy link

Krigu commented Sep 25, 2018

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

miwroblewski added a commit to miwroblewski/postgresql-embedded that referenced this issue Sep 25, 2018
142: Cached server path fails to find PID on Unix

Task-Url: yandex-qatools#142
@hopkinsjason
Copy link

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
Copy link

glickid commented Aug 1, 2019

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
Copy link

The same error...

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests

8 participants