dokku-postgres: Intermittent "missing" container status when created using "postgres:create servicename"

[vanastassiou]

I used a GraphQL mutation in a locally installed GraphiQL UI to create pgtest, but got an error (that I didn't log and cannot duplicate) when using a mutation to postgres:link the new service to an existing app. Here is some troubleshooting I attempted:

root@7d2db7ddee87:/app# dokku postgres:create pgtest
Postgres service pgtest already exists
root@7d2db7ddee87:/app# dokku postgres:list
cat: /var/lib/dokku/services/postgres/pgtest/ID: No such file or directory
NAME    VERSION        STATUS   EXPOSED PORTS  LINKS
pgtest  postgres:11.2  missing  -  
root@7d2db7ddee87:/app# dokku postgres:start pgtest
 !     Service is already started
root@7d2db7ddee87:/app# dokku postgres:list
cat: /var/lib/dokku/services/postgres/pgtest/ID: No such file or directory
NAME       VERSION        STATUS   EXPOSED PORTS  LINKS
pgtest     postgres:11.2  missing  -              -
pgtestcli  postgres:11.2  running  -              -

For comparison purposes, I created a service directly in the container:

       Waiting for container to be ready
       Creating container database
       Securing connection to database
=====> Postgres container created: pgtestcli
=====> Container Information
       Config dir:          /var/lib/dokku/services/postgres/pgtestcli/config
       Data dir:            /var/lib/dokku/services/postgres/pgtestcli/data
       Dsn:                 postgres://postgres:6e09057251dac857c20825ad53ac24a4@dokku-postgres-pgtestcli:5432/pgtestcli
       Exposed ports:       -                        
       Id:                  01efa245c62606f5317207f06c3580d3789707a396e90b14844d2a8cdbb9a40a
       Internal ip:         172.17.0.21              
       Links:               -                        
       Service root:        /var/lib/dokku/services/postgres/pgtestcli
       Status:              running                  
       Version:             postgres:11.2
root@7d2db7ddee87:/app# dokku postgres:list
cat: /var/lib/dokku/services/postgres/pgtest/ID: No such file or directory     
NAME       VERSION        STATUS   EXPOSED PORTS  LINKS
pgtest     postgres:11.2  missing  -              -
pgtestcli  postgres:11.2  running  -              -       

To test the mutation again, I created pgtestagain and it did not duplicate the error:

root@7d2db7ddee87:/app# dokku postgres:list
cat: /var/lib/dokku/services/postgres/pgtest/ID: No such file or directory
NAME         VERSION        STATUS   EXPOSED PORTS  LINKS
pgtest       postgres:11.2  missing  -              -
pgtestagain  postgres:11.2  running  -              -
pgtestcli    postgres:11.2  running  -              -    

Here's a trace of the start command for the defective container:

root@7d2db7ddee87:/app# dokku --trace postgres:start pgtest
+ export DOKKU_HOST_ROOT=[redacted]
+ DOKKU_HOST_ROOT=[redacted]
+ export DOKKU_DISTRO
++ . /etc/os-release
++ echo ubuntu
+ DOKKU_DISTRO=ubuntu
+ export DOKKU_IMAGE=[redacted]
+ DOKKU_IMAGE=[redacted]
+ export DOKKU_LIB_ROOT=/var/lib/dokku
+ DOKKU_LIB_ROOT=/var/lib/dokku
+ export PLUGIN_PATH=/var/lib/dokku/plugins
+ PLUGIN_PATH=/var/lib/dokku/plugins
+ export PLUGIN_AVAILABLE_PATH=/var/lib/dokku/plugins/available
+ PLUGIN_AVAILABLE_PATH=/var/lib/dokku/plugins/available
+ export PLUGIN_ENABLED_PATH=/var/lib/dokku/plugins/enabled
+ PLUGIN_ENABLED_PATH=/var/lib/dokku/plugins/enabled
+ export PLUGIN_CORE_PATH=/var/lib/dokku/core-plugins
+ PLUGIN_CORE_PATH=/var/lib/dokku/core-plugins
+ export PLUGIN_CORE_AVAILABLE_PATH=/var/lib/dokku/core-plugins/available
+ PLUGIN_CORE_AVAILABLE_PATH=/var/lib/dokku/core-plugins/available
+ export PLUGIN_CORE_ENABLED_PATH=/var/lib/dokku/core-plugins/enabled
+ PLUGIN_CORE_ENABLED_PATH=/var/lib/dokku/core-plugins/enabled
+ export DOKKU_SYSTEM_GROUP=dokku
+ DOKKU_SYSTEM_GROUP=dokku
+ export DOKKU_SYSTEM_USER=dokku
+ DOKKU_SYSTEM_USER=dokku
+ export DOKKU_API_VERSION=1
+ DOKKU_API_VERSION=1
+ export DOKKU_NOT_IMPLEMENTED_EXIT=10
+ DOKKU_NOT_IMPLEMENTED_EXIT=10
+ export DOKKU_VALID_EXIT=0
+ DOKKU_VALID_EXIT=0
+ export DOKKU_LOGS_DIR=/var/log/dokku
+ DOKKU_LOGS_DIR=/var/log/dokku
+ export DOKKU_EVENTS_LOGFILE=/var/log/dokku/events.log
+ DOKKU_EVENTS_LOGFILE=/var/log/dokku/events.log
+ export DOKKU_CONTAINER_LABEL=dokku
+ DOKKU_CONTAINER_LABEL=dokku
+ export DOKKU_GLOBAL_RUN_ARGS=--label=dokku
+ DOKKU_GLOBAL_RUN_ARGS=--label=dokku
+ source /var/lib/dokku/core-plugins/available/common/functions
++ set -eo pipefail
++ [[ -n 1 ]]
++ set -x
+ parse_args postgres:start pgtest
+ declare 'desc=top-level cli arg parser'
+ local next_index=1
+ local skip=false
+ args=("$@")
+ local args
+ for arg in "$@"
+ [[ false == \t\r\u\e ]]
+ case "$arg" in
+ next_index=2
+ for arg in "$@"
+ [[ false == \t\r\u\e ]]
+ case "$arg" in
+ next_index=3
+ return 0
+ args=("$@")
+ skip_arg=false
+ [[ postgres:start =~ ^--.* ]]
+ has_tty
+ declare 'desc=return 0 if we have a tty'
++ /usr/bin/tty
+ [[ /dev/pts/0 == \n\o\t\ \a\ \t\t\y ]]
+ return 0
++ id -un
+ [[ dokku != \d\o\k\k\u ]]
+ [[ postgres:start =~ ^plugin:.* ]]
+ [[ postgres:start == \s\s\h\-\k\e\y\s\:\a\d\d ]]
+ [[ -n '' ]]
+ dokku_auth postgres:start pgtest
+ declare 'desc=calls user-auth plugin trigger'
+ export SSH_USER=root
+ SSH_USER=root
+ export SSH_NAME=default
+ SSH_NAME=default
+ plugn trigger user-auth root default postgres:start pgtest
+ source /var/lib/dokku/core-plugins/available/common/functions
++ set -eo pipefail
++ [[ -n 1 ]]
++ set -x
+ [[ ! -n '' ]]
+ source /var/lib/dokku/core-plugins/available/common/functions
++ set -eo pipefail
++ [[ -n 1 ]]
++ set -x
++ dirname /var/lib/dokku/plugins/enabled/acl/user-auth
+ source /var/lib/dokku/plugins/enabled/acl/internal-functions
++ source /var/lib/dokku/core-plugins/available/common/functions
+++ set -eo pipefail
+++ [[ -n 1 ]]
+++ set -x
++ set -eo pipefail
++ [[ -n 1 ]]
++ set -x
+ DOKKU_SUPER_USER=not_a_valid_username_due_to_length
+ DOKKU_ACL_USER_COMMANDS='help version ps:help redis:help'
+ DOKKU_ACL_PER_APP_COMMANDS='apps:lock apps:unlock logs logs:failed urls ps ps:rebuild ps:report ps:restart ps:stop ps:start ps:scale git-upload-pack git-upload-archive git-receive-pack git-hook storage:list'
+ DOKKU_ACL_PER_SERVICE_COMMANDS='redis:connect redis:enter redis:export redis:import redis:info redis:logs redis:restart redis:start redis:stop redis:unexpose postgres:connect postgres:enter postgres:export postgres:import postgres:info postgres:logs postgres:restart postgres:start postgres:stop postgres:unexpose'
+ DOKKU_ACL_LINK_COMMANDS='redis:link redis:unlink'
+ SSH_USER=root
+ SSH_NAME=default
+ shift 2
+ [[ -z help version ps:help redis:help ]]
+ [[ root == \r\o\o\t ]]
+ exit 0
+ source /var/lib/dokku/core-plugins/available/common/functions
++ set -eo pipefail
++ [[ -n 1 ]]
++ set -x
+ [[ postgres:start =~ (ssh-keys:add|ssh-keys:remove) ]]
+ return 0
+ case "$1" in
+ execute_dokku_cmd postgres:start pgtest
+ declare 'desc=executes dokku sub-commands'
+ local PLUGIN_NAME=postgres:start
+ local PLUGIN_CMD=postgres:start
+ local implemented=0
+ local script
+ argv=("$@")
+ local argv
+ case "$PLUGIN_NAME" in
++ readlink -f /var/lib/dokku/plugins/enabled/postgres
+ [[ /var/lib/dokku/plugins/available/postgres == *core-plugins* ]]
+ [[ -x /var/lib/dokku/plugins/enabled/postgres:start/subcommands/default ]]
+ [[ -x /var/lib/dokku/plugins/enabled/postgres:start/subcommands/postgres:start ]]
+ [[ -x /var/lib/dokku/plugins/enabled/postgres/subcommands/start ]]
+ [[ -n start ]]
+ /var/lib/dokku/plugins/enabled/postgres/subcommands/start postgres:start pgtest
+ source /var/lib/dokku/plugins/enabled/common/functions
++ set -eo pipefail
++ [[ -n 1 ]]
++ set -x
++++ dirname /var/lib/dokku/plugins/enabled/postgres/subcommands/start
+++ cd /var/lib/dokku/plugins/enabled/postgres/subcommands
+++ pwd
++ dirname /var/lib/dokku/plugins/enabled/postgres/subcommands
+ source /var/lib/dokku/plugins/enabled/postgres/functions
++++ dirname /var/lib/dokku/plugins/enabled/postgres/functions
+++ cd /var/lib/dokku/plugins/enabled/postgres
+++ pwd
++ source /var/lib/dokku/plugins/enabled/postgres/config
+++ export POSTGRES_IMAGE=postgres
+++ POSTGRES_IMAGE=postgres
+++ export POSTGRES_IMAGE_VERSION=11.2
+++ POSTGRES_IMAGE_VERSION=11.2
+++ export POSTGRES_ROOT=/var/lib/dokku/services/postgres
+++ POSTGRES_ROOT=/var/lib/dokku/services/postgres
+++ export POSTGRES_HOST_ROOT=/var/lib/dokku/services/postgres
+++ POSTGRES_HOST_ROOT=/var/lib/dokku/services/postgres
+++ PLUGIN_UNIMPLEMENTED_SUBCOMMANDS=()
+++ export PLUGIN_UNIMPLEMENTED_SUBCOMMANDS
+++ export PLUGIN_COMMAND_PREFIX=postgres
+++ PLUGIN_COMMAND_PREFIX=postgres
+++ export PLUGIN_CONFIG_ROOT=/var/lib/dokku/config/postgres
+++ PLUGIN_CONFIG_ROOT=/var/lib/dokku/config/postgres
+++ export PLUGIN_DATA_ROOT=/var/lib/dokku/services/postgres
+++ PLUGIN_DATA_ROOT=/var/lib/dokku/services/postgres
+++ export PLUGIN_DATA_HOST_ROOT=/var/lib/dokku/services/postgres
+++ PLUGIN_DATA_HOST_ROOT=/var/lib/dokku/services/postgres
+++ PLUGIN_DATASTORE_PORTS=(5432)
+++ export PLUGIN_DATASTORE_PORTS
+++ export PLUGIN_DATASTORE_WAIT_PORT=5432
+++ PLUGIN_DATASTORE_WAIT_PORT=5432
+++ export PLUGIN_DEFAULT_ALIAS=DATABASE
+++ PLUGIN_DEFAULT_ALIAS=DATABASE
+++ export PLUGIN_DISABLE_PULL=
+++ PLUGIN_DISABLE_PULL=
+++ export PLUGIN_DISABLE_PULL_VARIABLE=POSTGRES_DISABLE_PULL
+++ PLUGIN_DISABLE_PULL_VARIABLE=POSTGRES_DISABLE_PULL
+++ export PLUGIN_ALT_ALIAS=DOKKU_POSTGRES
+++ PLUGIN_ALT_ALIAS=DOKKU_POSTGRES
+++ export PLUGIN_IMAGE=postgres
+++ PLUGIN_IMAGE=postgres
+++ export PLUGIN_IMAGE_VERSION=11.2
+++ PLUGIN_IMAGE_VERSION=11.2
+++ export PLUGIN_SCHEME=postgres
+++ PLUGIN_SCHEME=postgres
+++ export PLUGIN_SERVICE=Postgres
+++ PLUGIN_SERVICE=Postgres
+++ export PLUGIN_VARIABLE=POSTGRES
+++ PLUGIN_VARIABLE=POSTGRES
+++ export PLUGIN_BASE_PATH=/var/lib/dokku/plugins
+++ PLUGIN_BASE_PATH=/var/lib/dokku/plugins
+++ [[ -n 1 ]]
+++ export PLUGIN_BASE_PATH=/var/lib/dokku/plugins/enabled
+++ PLUGIN_BASE_PATH=/var/lib/dokku/plugins/enabled
+++ [[ -d /var/lib/dokku/services/postgres/* ]]
++ set -eo pipefail
++ [[ -n 1 ]]
++ set -x
++++ dirname /var/lib/dokku/plugins/enabled/postgres/functions
+++ cd /var/lib/dokku/plugins/enabled/postgres
+++ pwd
++ source /var/lib/dokku/plugins/enabled/postgres/common-functions
+++ set -eo pipefail
+++ [[ -n 1 ]]
+++ set -x
+++ source /var/lib/dokku/plugins/available/config/functions
++++ set -eo pipefail
++++ [[ -n 1 ]]
++++ set -x
++++ source /var/lib/dokku/core-plugins/available/common/functions
+++++ set -eo pipefail
+++++ [[ -n 1 ]]
+++++ set -x
++ source /var/lib/dokku/plugins/enabled/common/functions
+++ set -eo pipefail
+++ [[ -n 1 ]]
+++ set -x
++ source /var/lib/dokku/plugins/available/config/functions
+++ set -eo pipefail
+++ [[ -n 1 ]]
+++ set -x
+++ source /var/lib/dokku/core-plugins/available/common/functions
++++ set -eo pipefail
++++ [[ -n 1 ]]
++++ set -x
++ [[ -f /var/lib/dokku/plugins/available/docker-options/functions ]]
++ source /var/lib/dokku/plugins/available/docker-options/functions
+++ set -eo pipefail
+++ [[ -n 1 ]]
+++ set -x
+++ source /var/lib/dokku/core-plugins/available/common/functions
++++ set -eo pipefail
++++ [[ -n 1 ]]
++++ set -x
+++ AVAILABLE_PHASES=(build deploy run)
+ service-start-cmd postgres:start pgtest
+ declare 'desc=start a previously stopped Postgres service'
+ argv=("$@")
+ local cmd=postgres:start argv
+ [[ postgres:start == \p\o\s\t\g\r\e\s\:\s\t\a\r\t ]]
+ shift 1
+ declare SERVICE=pgtest
+ [[ -z pgtest ]]
+ verify_service_name pgtest
+ declare 'desc=Verifies that a service exists'
+ declare SERVICE=pgtest
+ [[ -z pgtest ]]
+ [[ ! -d /var/lib/dokku/services/postgres/pgtest ]]
+ return 0
+ service_start pgtest
+ local SERVICE=pgtest
+ local QUIET=
+ local SERVICE_ROOT=/var/lib/dokku/services/postgres/pgtest
++ get_service_name pgtest
++ declare 'desc=Retrieves a docker service label'
++ declare SERVICE=pgtest
++ echo dokku.postgres.pgtest
+ local SERVICE_NAME=dokku.postgres.pgtest
++ docker ps -aq --no-trunc --filter status=running --filter 'name=^/dokku.postgres.pgtest$' --format '{{ .ID }}'
+ local ID=af0a42dbe84acde2a0c573cb21ed5d10b71b9dc57ff1ac4cfd8aec557588f0ff
+ [[ -n af0a42dbe84acde2a0c573cb21ed5d10b71b9dc57ff1ac4cfd8aec557588f0ff ]]
+ [[ -z '' ]]
+ dokku_log_warn 'Service is already started'
+ declare 'desc=log warning formatter'
+ echo ' !     Service is already started'
 !     Service is already started
+ return 0
+ implemented=1
+ [[ 1 -eq 0 ]]
+ [[ 1 -eq 0 ]]

[vanastassiou]

Workaround: create missing /var/lib/dokku/services/postgres/pgtest/ID file containing the local ID value from the trace.

[vanastassiou]

I was able to duplicate the issue as follows:

1. Use GraphQL mutation directly in GraphiQL to create new Postgres service testone
2. Delete using GraphQL mutation and confirm clean deletion in shell with postgres:list
3. Repeat Step 1
4. Use my app's front end to delete the service
5. Repeat Step 1, which gives me: "Command '['/usr/bin/dokku', 'postgres:create', 'testone']' returned non-zero exit status 1."
6. Run postgres:list in container; the service will still be listed, but missing status

Also this way:

1. Use GraphQL mutation directly in GraphiQL to create new Postgres service testthree
2. Use mutation to delete testthree
3. Use mutation to add testthree to get error "Command '['/usr/bin/dokku', 'postgres:create', 'three']' returned non-zero exit status 1."
4. Run postgres:list in container; the service will still be listed, but perpetually restarting status

So this does look intermittent after all.

I also ran into something else that's interesting:

1. Use GraphQL mutation to create two new Postgres services (testone and testonetwo)
2. Use my app's front end to delete testone
3. Run postgres:list in container; the service will still be listed, but missing status
4. Run postgres:destroy testone and confirm
5. Run postgres:list in container; both testone and testonetwo will be missing

The Postgres containers also don't seem to be persistent between container rebuilds; nothing shows up when I postgres:list, but if I try to re-add a service, I get the same error messages as in steps 5-6 in my first above section (no problems with the Redis services). I haven't yet investigated enough to be sure whether this is a plugin issue or my app's issue.

[josegonzalez]

I tested this with raw service calls:

# dokku postgres:create testone
       Waiting for container to be ready
       Creating container database
       Securing connection to database
=====> Postgres container created: testone
=====> Container Information
       Config dir:          /var/lib/dokku/services/postgres/testone/config
       Data dir:            /var/lib/dokku/services/postgres/testone/data
       Dsn:                 postgres://postgres:bca5c4e6f60f44c6f9ee163e04a5b6ba@dokku-postgres-testone:5432/testone
       Exposed ports:       -
       Id:                  b3d5bae7f7d8de3ea32ca48acd272d03a8f40dcd4f36a14913ce7c290f64405c
       Internal ip:         172.17.0.33
       Links:               -
       Service root:        /var/lib/dokku/services/postgres/testone
       Status:              running
       Version:             postgres:11.2
root@www-1:/var/lib/dokku/plugins/enabled/postgres# dokku --force postgres:destroy testone
=====> Deleting testone
=====> Stopping container
       Container stopped
       Removing container
       Removing data
=====> Postgres container deleted: testone
root@www-1:/var/lib/dokku/plugins/enabled/postgres# dokku postgres:create testone
       Waiting for container to be ready
       Creating container database
       Securing connection to database
=====> Postgres container created: testone
=====> Container Information
       Config dir:          /var/lib/dokku/services/postgres/testone/config
       Data dir:            /var/lib/dokku/services/postgres/testone/data
       Dsn:                 postgres://postgres:6d80c473d4d0b4056a424aac1d71b7e2@dokku-postgres-testone:5432/testone
       Exposed ports:       -
       Id:                  6dd9eb55b0f39213157dbbc25b9d9c6d459198ed15c62b7ec78817bed5721d45
       Internal ip:         172.17.0.33
       Links:               -
       Service root:        /var/lib/dokku/services/postgres/testone
       Status:              running
       Version:             postgres:11.2
root@www-1:/var/lib/dokku/plugins/enabled/postgres# dokku postgres:list
NAME                 VERSION        STATUS   EXPOSED PORTS  LINKS
gene                 postgres:10.2  running  -              -
roddenberry          postgres:10.1  running  -              -
service_with_dashes  postgres:11.2  running  -              -
testone              postgres:11.2  running  -              -

Might be something in the app that is causing the service creation/destruction to bail in a weird way...

We definitely still have an issue where postgres:start should correctly start the service even if it's "missing" though.

[josegonzalez]

The 1.8.1 release of all the plugins now properly handles :start calls. Any other issues regarding containers missing etc. is something that probably is in your app code, and can't be fixed in this plugin.