Postgresql error: FATAL: role "loraserver_ns" does not exist (Docker setup)

dhausner · June 18, 2018, 8:55pm

I’m getting the following error that repeats every 2s with each retry:
postgresql_1 | FATAL: role “loraserver_ns” does not exist
postgresql_1 | FATAL: role “loraserver_as” does not exist
loraserver_1 | time=“2018-06-18T20:44:53Z” level=error msg=“ping database error, will retry in 2s: pq: role “loraserver_ns” does not exist”
appserver_1 | time=“2018-06-18T20:44:53Z” level=error msg="ping database error, will retry in 2s: pq: role “loraserver_as” does not exist

The 001-init-loraserver_ns.sh and 002-init-loraserver_as.sh files are both in configuration/postgresql/initdb, but it doesn’t seem as if either one of them are being used to create those roles upon using the “docker-compose up” command in the loraserver-docker folder.

Any help will be greatly appreciated, and I’m happy to provide more information.

dhausner · June 18, 2018, 9:00pm

More information. After using “docker-compose down” and “docker-compose up” again, I get the following lines that end in an error.
postgresql_1 | server started
postgresql_1 | ALTER ROLE
postgresql_1 |
postgresql_1 |
postgresql_1 | /usr/local/bin/docker-entrypoint.sh: running /docker-entrypoint-initdb.d/001-init-loraserver_ns.sh
postgresql_1 | /usr/local/bin/docker-entrypoint.sh: /docker-entrypoint-initdb.d/001-init-loraserver_ns.sh: /bin/bash^M: bad interpreter: No such file or directory
loraserver-docker_postgresql_1 exited with code 126
loraserver_1 | time=“2018-06-18T20:56:32Z” level=error msg=“ping database error, will retry in 2s: dial tcp: lookup postgresql on 127.0.0.11:53: no such host”

brocaar · June 19, 2018, 7:33am

I’m unable to reproduce your issue. See below my logs. There are some initial errors, but they are caused because of the async startup of all services (e.g. PostgreSQL is still initializing when LoRa (App) Server is trying to connect). This only takes a couple of seconds:

/p/tmp $ git clone git@github.com:brocaar/loraserver-docker.git
Cloning into 'loraserver-docker'...
remote: Counting objects: 23, done.
remote: Total 23 (delta 0), reused 0 (delta 0), pack-reused 23
Receiving objects: 100% (23/23), 12.69 KiB | 12.69 MiB/s, done.
Resolving deltas: 100% (5/5), done.
/p/tmp $ cd loraserver-docker/
/p/t/loraserver-docker (master|✔) $ docker-compose up
Recreating loraserver-docker_redis_1         ... done
Recreating loraserver-docker_appserver_1     ... done
Recreating loraserver-docker_gatewaybridge_1 ... done
Recreating loraserver-docker_postgresql_1    ... done
Starting loraserver-docker_mosquitto_1       ... done
Recreating loraserver-docker_loraserver_1    ... done
Attaching to loraserver-docker_mosquitto_1, loraserver-docker_gatewaybridge_1, loraserver-docker_appserver_1, loraserver-docker_loraserver_1, loraserver-docker_redis_1, loraserver-docker_postgresql_1
gatewaybridge_1  | time="2018-06-19T07:29:13Z" level=info msg="starting LoRa Gateway Bridge" docs="https://www.loraserver.io/lora-gateway-bridge/" version=2.4.1
gatewaybridge_1  | time="2018-06-19T07:29:13Z" level=info msg="backend: TLS config is empty"
gatewaybridge_1  | time="2018-06-19T07:29:13Z" level=info msg="backend: connecting to mqtt broker" server="tcp://mosquitto:1883"
gatewaybridge_1  | time="2018-06-19T07:29:13Z" level=info msg="gateway: starting gateway udp listener" addr="0.0.0.0:1700"
gatewaybridge_1  | time="2018-06-19T07:29:13Z" level=info msg="backend: connected to mqtt broker"
appserver_1      | time="2018-06-19T07:29:13Z" level=info msg="starting LoRa App Server" docs="https://www.loraserver.io/" version=1.0.0
appserver_1      | time="2018-06-19T07:29:13Z" level=info msg="connecting to postgresql"
gatewaybridge_1  | time="2018-06-19T07:29:13Z" level=info msg="gateway: received udp packet from gateway" addr="172.18.0.1:46817" protocol_version=2 type=PullData
loraserver_1     | time="2018-06-19T07:29:13Z" level=info msg="starting LoRa Server" band=EU_863_870 docs="https://docs.loraserver.io/" net_id=010203 version=1.0.0
redis_1          | 1:C 19 Jun 07:29:14.401 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
redis_1          | 1:C 19 Jun 07:29:14.401 # Redis version=4.0.9, bits=64, commit=00000000, modified=0, pid=1, just started
redis_1          | 1:C 19 Jun 07:29:14.401 # Warning: no config file specified, using the default config. In order to specify a config file use redis-server /path/to/redis.conf
redis_1          | 1:M 19 Jun 07:29:14.404 * Running mode=standalone, port=6379.
redis_1          | 1:M 19 Jun 07:29:14.404 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
redis_1          | 1:M 19 Jun 07:29:14.404 # Server initialized
redis_1          | 1:M 19 Jun 07:29:14.404 # WARNING you have Transparent Huge Pages (THP) support enabled in your kernel. This will create latency and memory usage issues with Redis. To fix this issue run the command 'echo never > /sys/kernel/mm/transparent_hugepage/enabled' as root, and add it to your /etc/rc.local in order to retain the setting after a reboot. Redis must be restarted after THP is disabled.
redis_1          | 1:M 19 Jun 07:29:14.404 * Ready to accept connections
gatewaybridge_1  | time="2018-06-19T07:29:13Z" level=info msg="backend: subscribing to topic" qos=0 topic=gateway/00800000a00016b6/tx
loraserver_1     | time="2018-06-19T07:29:13Z" level=info msg="setup redis connection pool" url="redis://redis:6379"
loraserver_1     | time="2018-06-19T07:29:13Z" level=info msg="connecting to postgresql"
gatewaybridge_1  | time="2018-06-19T07:29:13Z" level=info msg="backend: subscribing to topic" qos=0 topic=gateway/00800000a00016b6/config
gatewaybridge_1  | time="2018-06-19T07:29:13Z" level=info msg="gateway: sending udp packet to gateway" addr="172.18.0.1:46817" protocol_version=2 type=PullACK
postgresql_1     | The files belonging to this database system will be owned by user "postgres".
postgresql_1     | This user must also own the server process.
postgresql_1     |
postgresql_1     | The database cluster will be initialized with locale "en_US.utf8".
postgresql_1     | The default database encoding has accordingly been set to "UTF8".
postgresql_1     | The default text search configuration will be set to "english".
postgresql_1     |
postgresql_1     | Data page checksums are disabled.
postgresql_1     |
postgresql_1     | fixing permissions on existing directory /var/lib/postgresql/data ... ok
postgresql_1     | creating subdirectories ... ok
postgresql_1     | selecting default max_connections ... 100
postgresql_1     | selecting default shared_buffers ... 128MB
postgresql_1     | selecting dynamic shared memory implementation ... posix
loraserver_1     | time="2018-06-19T07:29:14Z" level=error msg="ping database error, will retry in 2s: dial tcp 172.18.0.7:5432: connect: connection refused"
appserver_1      | time="2018-06-19T07:29:14Z" level=error msg="ping database error, will retry in 2s: dial tcp 172.18.0.7:5432: connect: connection refused"
postgresql_1     | creating configuration files ... ok
loraserver_1     | time="2018-06-19T07:29:16Z" level=error msg="ping database error, will retry in 2s: dial tcp 172.18.0.7:5432: connect: connection refused"
appserver_1      | time="2018-06-19T07:29:16Z" level=error msg="ping database error, will retry in 2s: dial tcp 172.18.0.7:5432: connect: connection refused"
postgresql_1     | running bootstrap script ... ok
postgresql_1     | performing post-bootstrap initialization ... sh: locale: not found
postgresql_1     | No usable system locales were found.
postgresql_1     | Use the option "--debug" to see details.
loraserver_1     | time="2018-06-19T07:29:18Z" level=error msg="ping database error, will retry in 2s: dial tcp 172.18.0.7:5432: connect: connection refused"
appserver_1      | time="2018-06-19T07:29:18Z" level=error msg="ping database error, will retry in 2s: dial tcp 172.18.0.7:5432: connect: connection refused"
appserver_1      | time="2018-06-19T07:29:20Z" level=error msg="ping database error, will retry in 2s: dial tcp 172.18.0.7:5432: connect: connection refused"
loraserver_1     | time="2018-06-19T07:29:20Z" level=error msg="ping database error, will retry in 2s: dial tcp 172.18.0.7:5432: connect: connection refused"
loraserver_1     | time="2018-06-19T07:29:22Z" level=error msg="ping database error, will retry in 2s: dial tcp 172.18.0.7:5432: connect: connection refused"
appserver_1      | time="2018-06-19T07:29:22Z" level=error msg="ping database error, will retry in 2s: dial tcp 172.18.0.7:5432: connect: connection refused"
postgresql_1     | ok
gatewaybridge_1  | time="2018-06-19T07:29:24Z" level=info msg="gateway: received udp packet from gateway" addr="172.18.0.1:46817" protocol_version=2 type=PullData
gatewaybridge_1  | time="2018-06-19T07:29:24Z" level=info msg="gateway: sending udp packet to gateway" addr="172.18.0.1:46817" protocol_version=2 type=PullACK
loraserver_1     | time="2018-06-19T07:29:24Z" level=error msg="ping database error, will retry in 2s: dial tcp 172.18.0.7:5432: connect: connection refused"
appserver_1      | time="2018-06-19T07:29:24Z" level=error msg="ping database error, will retry in 2s: dial tcp 172.18.0.7:5432: connect: connection refused"
gatewaybridge_1  | time="2018-06-19T07:29:25Z" level=info msg="gateway: received udp packet from gateway" addr="172.18.0.1:44202" protocol_version=2 type=PushData
gatewaybridge_1  | time="2018-06-19T07:29:25Z" level=info msg="gateway: stat packet received" addr="172.18.0.1:44202" mac=00800000a00016b6
gatewaybridge_1  | time="2018-06-19T07:29:25Z" level=info msg="backend: publishing packet" qos=0 topic=gateway/00800000a00016b6/stats
gatewaybridge_1  | time="2018-06-19T07:29:25Z" level=info msg="gateway: sending udp packet to gateway" addr="172.18.0.1:44202" protocol_version=2 type=PushACK
postgresql_1     | syncing data to disk ...
postgresql_1     | WARNING: enabling "trust" authentication for local connections
postgresql_1     | You can change this by editing pg_hba.conf or using the option -A, or
postgresql_1     | --auth-local and --auth-host, the next time you run initdb.
postgresql_1     | ok
postgresql_1     |
postgresql_1     | Success. You can now start the database server using:
postgresql_1     |
postgresql_1     |     pg_ctl -D /var/lib/postgresql/data -l logfile start
postgresql_1     |
postgresql_1     | ****************************************************
postgresql_1     | WARNING: No password has been set for the database.
postgresql_1     |          This will allow anyone with access to the
postgresql_1     |          Postgres port to access your database. In
postgresql_1     |          Docker's default configuration, this is
postgresql_1     |          effectively any other container on the same
postgresql_1     |          system.
postgresql_1     |
postgresql_1     |          Use "-e POSTGRES_PASSWORD=password" to set
postgresql_1     |          it in "docker run".
postgresql_1     | ****************************************************
postgresql_1     | waiting for server to start....LOG:  database system was shut down at 2018-06-19 07:29:23 UTC
postgresql_1     | LOG:  MultiXact member wraparound protections are now enabled
postgresql_1     | LOG:  database system is ready to accept connections
postgresql_1     | LOG:  autovacuum launcher started
postgresql_1     |  done
postgresql_1     | server started
postgresql_1     | ALTER ROLE
postgresql_1     |
postgresql_1     |
postgresql_1     | /usr/local/bin/docker-entrypoint.sh: running /docker-entrypoint-initdb.d/001-init-loraserver_ns.sh
postgresql_1     | CREATE ROLE
loraserver_1     | time="2018-06-19T07:29:26Z" level=error msg="ping database error, will retry in 2s: dial tcp 172.18.0.7:5432: connect: connection refused"
appserver_1      | time="2018-06-19T07:29:26Z" level=error msg="ping database error, will retry in 2s: dial tcp 172.18.0.7:5432: connect: connection refused"
postgresql_1     | CREATE DATABASE
postgresql_1     |
postgresql_1     | /usr/local/bin/docker-entrypoint.sh: running /docker-entrypoint-initdb.d/002-init-loraserver_as.sh
postgresql_1     | CREATE ROLE
appserver_1      | time="2018-06-19T07:29:28Z" level=error msg="ping database error, will retry in 2s: dial tcp 172.18.0.7:5432: connect: connection refused"
loraserver_1     | time="2018-06-19T07:29:28Z" level=error msg="ping database error, will retry in 2s: dial tcp 172.18.0.7:5432: connect: connection refused"
postgresql_1     | CREATE DATABASE
postgresql_1     |
postgresql_1     | /usr/local/bin/docker-entrypoint.sh: running /docker-entrypoint-initdb.d/003-loraserver_as_trgm.sh
postgresql_1     | CREATE EXTENSION
postgresql_1     |
postgresql_1     | LOG:  received fast shutdown request
postgresql_1     | LOG:  aborting any active transactions
postgresql_1     | waiting for server to shut down...LOG:  autovacuum launcher shutting down
postgresql_1     | .LOG:  shutting down
postgresql_1     | LOG:  database system is shut down
loraserver_1     | time="2018-06-19T07:29:30Z" level=error msg="ping database error, will retry in 2s: dial tcp 172.18.0.7:5432: connect: connection refused"
appserver_1      | time="2018-06-19T07:29:30Z" level=error msg="ping database error, will retry in 2s: dial tcp 172.18.0.7:5432: connect: connection refused"
postgresql_1     |  done
postgresql_1     | server stopped
postgresql_1     |
postgresql_1     | PostgreSQL init process complete; ready for start up.
postgresql_1     |
postgresql_1     | LOG:  database system was shut down at 2018-06-19 07:29:29 UTC
postgresql_1     | LOG:  MultiXact member wraparound protections are now enabled
postgresql_1     | LOG:  database system is ready to accept connections
postgresql_1     | LOG:  autovacuum launcher started
appserver_1      | time="2018-06-19T07:29:32Z" level=info msg="setup redis connection pool"
appserver_1      | time="2018-06-19T07:29:32Z" level=info msg="handler/mqtt: TLS config is empty"
appserver_1      | time="2018-06-19T07:29:32Z" level=info msg="handler/mqtt: connecting to mqtt broker" server="tcp://mosquitto:1883"
loraserver_1     | time="2018-06-19T07:29:32Z" level=info msg="backend/gateway: TLS config is empty"
loraserver_1     | time="2018-06-19T07:29:32Z" level=info msg="backend/gateway: connecting to mqtt broker" server="tcp://mosquitto:1883"
appserver_1      | time="2018-06-19T07:29:32Z" level=info msg="applying database migrations"
loraserver_1     | time="2018-06-19T07:29:32Z" level=info msg="configuring join-server client" ca_cert= server="http://appserver:8003" tls_cert= tls_key=
loraserver_1     | time="2018-06-19T07:29:32Z" level=info msg="no network-controller configured"
loraserver_1     | time="2018-06-19T07:29:32Z" level=info msg="applying database migrations"
loraserver_1     | time="2018-06-19T07:29:32Z" level=info msg="backend/gateway: connected to mqtt server"
loraserver_1     | time="2018-06-19T07:29:32Z" level=info msg="backend/gateway: subscribing to rx topic" qos=0 topic=gateway/+/rx
loraserver_1     | time="2018-06-19T07:29:32Z" level=info msg="backend/gateway: subscribing to stats topic" qos=0 topic=gateway/+/stats
appserver_1      | time="2018-06-19T07:29:32Z" level=info msg="handler/mqtt: connected to mqtt broker"
appserver_1      | time="2018-06-19T07:29:32Z" level=info msg="handler/mqtt: subscribing to tx topic" qos=0 topic=application/+/node/+/tx
loraserver_1     | time="2018-06-19T07:29:33Z" level=info msg="migrations applied" count=11
loraserver_1     | time="2018-06-19T07:29:33Z" level=info msg="starting api server" bind="0.0.0.0:8000" ca-cert= tls-cert= tls-key=
loraserver_1     | time="2018-06-19T07:29:33Z" level=info msg="starting downlink device-queue scheduler"
gatewaybridge_1  | time="2018-06-19T07:29:34Z" level=info msg="gateway: received udp packet from gateway" addr="172.18.0.1:46817" protocol_version=2 type=PullData
gatewaybridge_1  | time="2018-06-19T07:29:34Z" level=info msg="gateway: sending udp packet to gateway" addr="172.18.0.1:46817" protocol_version=2 type=PullACK
appserver_1      | time="2018-06-19T07:29:34Z" level=info msg="migrations applied" count=29
appserver_1      | time="2018-06-19T07:29:34Z" level=info msg="starting application-server api" bind="0.0.0.0:8001" ca-cert= tls-cert= tls-key=
appserver_1      | time="2018-06-19T07:29:34Z" level=info msg="starting join-server api" bind="0.0.0.0:8003" ca_cert= tls_cert= tls_key=
appserver_1      | time="2018-06-19T07:29:34Z" level=info msg="starting client api server" bind="0.0.0.0:8080" tls-cert=/etc/lora-app-server/certs/http.pem tls-key=/etc/lora-app-server/certs/http-key.pem
appserver_1      | time="2018-06-19T07:29:35Z" level=info msg="registering rest api handler and documentation endpoint" path=/api
gatewaybridge_1  | time="2018-06-19T07:29:44Z" level=info msg="gateway: received udp packet from gateway" addr="172.18.0.1:46817" protocol_version=2 type=PullData
gatewaybridge_1  | time="2018-06-19T07:29:44Z" level=info msg="gateway: sending udp packet to gateway" addr="172.18.0.1:46817" protocol_version=2 type=PullACK
appserver_1      | time="2018-06-19T07:29:53Z" level=info msg="finished streaming call with code NotFound" error="rpc error: code = NotFound desc = object does not exist" grpc.code=NotFound grpc.method=StreamFrameLogs grpc.service=api.Device grpc.start_time="2018-06-19T07:29:53Z" grpc.time_ms=89.399 peer.address="127.0.0.1:49300" span.kind=server system=grpc
gatewaybridge_1  | time="2018-06-19T07:29:54Z" level=info msg="gateway: received udp packet from gateway" addr="172.18.0.1:46817" protocol_version=2 type=PullData
gatewaybridge_1  | time="2018-06-19T07:29:54Z" level=info msg="gateway: sending udp packet to gateway" addr="172.18.0.1:46817" protocol_version=2 type=PullACK
gatewaybridge_1  | time="2018-06-19T07:29:55Z" level=info msg="gateway: received udp packet from gateway" addr="172.18.0.1:44202" protocol_version=2 type=PushData
gatewaybridge_1  | time="2018-06-19T07:29:55Z" level=info msg="gateway: stat packet received" addr="172.18.0.1:44202" mac=00800000a00016b6
gatewaybridge_1  | time="2018-06-19T07:29:55Z" level=info msg="backend: publishing packet" qos=0 topic=gateway/00800000a00016b6/stats
gatewaybridge_1  | time="2018-06-19T07:29:55Z" level=info msg="gateway: sending udp packet to gateway" addr="172.18.0.1:44202" protocol_version=2 type=PushACK
loraserver_1     | time="2018-06-19T07:29:55Z" level=info msg="backend/gateway: gateway stats packet received" mac=00800000a00016b6
loraserver_1     | time="2018-06-19T07:29:55Z" level=info msg="gateway created" mac=00800000a00016b6

dhausner · June 19, 2018, 4:08pm

I started with a fresh pull from github of loraserver-docker. Ran “docker-compose up” and got the following, with the same error. Clearly there’s some modification I need to make, but I’m drawing a blank as to what it is.

Starting loraserver-docker_loraserver_1 … done
Starting loraserver-docker_mosquitto_1 … done
Starting loraserver-docker_gatewaybridge_1 … done
Starting loraserver-docker_appserver_1 … done
Starting loraserver-docker_redis_1 … done
Starting loraserver-docker_postgresql_1 … done
Attaching to loraserver-docker_mosquitto_1, loraserver-docker_appserver_1, loraserver-docker_loraserver_1, loraserver-docker_postgresql_1, loraserver-docker_redis_1, loraserver-docker_gatewaybridge_1
appserver_1 | time=“2018-06-19T15:58:15Z” level=info msg=“starting LoRa App Server” docs=“https://www.loraserver.io/” version=1.0.0
appserver_1 | time=“2018-06-19T15:58:15Z” level=info msg=“connecting to postgresql”
loraserver_1 | time=“2018-06-19T15:58:15Z” level=info msg=“starting LoRa Server” band=EU_863_870 docs=“https://docs.loraserver.io/” net_id=010203 version=1.0.1
loraserver_1 | time=“2018-06-19T15:58:15Z” level=info msg=“setup redis connection pool” url=“redis://redis:6379”
loraserver_1 | time=“2018-06-19T15:58:15Z” level=info msg=“connecting to postgresql”
postgresql_1 | LOG: database system was shut down at 2018-06-19 15:55:55 UTC
postgresql_1 | LOG: MultiXact member wraparound protections are now enabled
postgresql_1 | LOG: database system is ready to accept connections
postgresql_1 | LOG: autovacuum launcher started
redis_1 | 1:C 19 Jun 15:58:16.502 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
redis_1 | 1:C 19 Jun 15:58:16.502 # Redis version=4.0.10, bits=64, commit=00000000, modified=0, pid=1, just started
redis_1 | 1:C 19 Jun 15:58:16.502 # Warning: no config file specified, using the default config. In order to specify a config file use redis-server /path/to/redis.conf
redis_1 | 1:M 19 Jun 15:58:16.503 * Running mode=standalone, port=6379.
redis_1 | 1:M 19 Jun 15:58:16.503 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
redis_1 | 1:M 19 Jun 15:58:16.503 # Server initialized
redis_1 | 1:M 19 Jun 15:58:16.503 # WARNING you have Transparent Huge Pages (THP) support enabled in your kernel. This will create latency and memory usage issues with Redis. To fix this issue run the command ‘echo never > /sys/kernel/mm/transparent_hugepage/enabled’ as root, and add it to your /etc/rc.local in order to retain the setting after a reboot. Redis must be restarted after THP is disabled.
redis_1 | 1:M 19 Jun 15:58:16.503 * Ready to accept connections
(Continued)

dhausner · June 19, 2018, 4:09pm

gatewaybridge_1 | time=“2018-06-19T15:58:16Z” level=info msg=“starting LoRa Gateway Bridge” docs=“Introduction - ChirpStack open-source LoRaWAN<sup>®</sup> Network Server” version=2.4.1
gatewaybridge_1 | time=“2018-06-19T15:58:16Z” level=info msg=“backend: TLS config is empty”
gatewaybridge_1 | time=“2018-06-19T15:58:16Z” level=info msg=“backend: connecting to mqtt broker” server=“tcp://mosquitto:1883”
gatewaybridge_1 | time=“2018-06-19T15:58:16Z” level=info msg=“gateway: starting gateway udp listener” addr=“0.0.0.0:1700”
gatewaybridge_1 | time=“2018-06-19T15:58:16Z” level=info msg=“backend: connected to mqtt broker”
postgresql_1 | FATAL: role “loraserver_as” does not exist
appserver_1 | time=“2018-06-19T15:58:16Z” level=error msg=“ping database error, will retry in 2s: pq: role "loraserver_as" does not exist”
postgresql_1 | FATAL: role “loraserver_ns” does not exist
loraserver_1 | time=“2018-06-19T15:58:16Z” level=error msg=“ping database error, will retry in 2s: pq: role "loraserver_ns" does not exist”
postgresql_1 | FATAL: role “loraserver_as” does not exist
appserver_1 | time=“2018-06-19T15:58:18Z” level=error msg=“ping database error, will retry in 2s: pq: role "loraserver_as" does not exist”
postgresql_1 | FATAL: role “loraserver_ns” does not exist
loraserver_1 | time=“2018-06-19T15:58:18Z” level=error msg=“ping database error, will retry in 2s: pq: role "loraserver_ns" does not exist”
appserver_1 | time=“2018-06-19T15:58:20Z” level=error msg=“ping database error, will retry in 2s: pq: role "loraserver_as" does not exist”
postgresql_1 | FATAL: role “loraserver_as” does not exist
postgresql_1 | FATAL: role “loraserver_ns” does not exist
loraserver_1 | time=“2018-06-19T15:58:20Z” level=error msg=“ping database error, will retry in 2s: pq: role "loraserver_ns" does not exist”
postgresql_1 | FATAL: role “loraserver_as” does not exist
appserver_1 | time=“2018-06-19T15:58:22Z” level=error msg=“ping database error, will retry in 2s: pq: role "loraserver_as" does not exist”
postgresql_1 | FATAL: role “loraserver_ns” does not exist

And the last few lines repeat until I terminate with Ctrl+C. (I waited over a minute to ensure that I wasn’t terminating too soon.)

dhausner · June 19, 2018, 4:30pm

Ah, solved it by running the bash scripts and creating those roles. I thought it would do it automatically, but doing it manually worked just as well. It’s running!

brocaar · June 20, 2018, 7:29am

It should be executed automatically (and it does for me). Are you sure you started from a clean state? E.g.

docker-compose stop # stop all docker containers
docker-compose rm   # remove all docker containers

Note that the PostgreSQL init scripts are only executed the first time on initialization.

Could other people test if they have the same issue?

JesusSanchez456 · January 23, 2019, 1:13pm

In case of any other user experiencing this problem, I found how to reproduce it, and a solution.

TL;DR, the culprit is the umask to something that masks all the other read permissions when cloning https://github.com/brocaar/loraserver-docker.git. Thus, the cloned workdir will have permissions like rwxrwx---. This will produce the problem of OP.

Long Answer

Postgresql reads the initdb configuration scripts directly from the host filesystem, this is specified in the docker-compose.yml. When you clone the repository (i.e. git clone https://github.com/brocaar/loraserver-docker.git) if you had umask 007 for example, all the files in the configuration/postgres/initdb will have rwxrwx--- permissions (or something similar). The key here is that other must have at least read access to the directory initdb and also the scripts. Something like chmod 755 initdb/ for example would work.

The docker image postgres:9.6-alpine runs /docker-entrypoint.sh when creating the container that will try to access the scripts in /docker-entrypoint-initdb.d/. If the file permissions for other are not set to r-x, the script in the docker host machine will never be executed.

How to reproduce:

Set your docker host machine umask to something that restricts the permissions of other, i.e. umask 007.
Clone the repository with git clone https://github.com/brocaar/loraserver-docker.git.
sudo rm -rf data/ && docker-compose up

Then the error will manifest.

How to solve:

Make sure that when cloning the repository, the workdir has read permissions for other, i.e. by setting your umask 002 or something like that. Make sure your configuration/postgres/initdb/ directory and the scripts inside has permissions for other, i.e. 755 or 777.

snspinn · July 28, 2021, 9:40am

A very belated (and incomplete) answer here. For the best answer see the @JesusSanchez456 post. Just filling in a blank here.

Regarding the issue mentioned where the error output included the line:

This is caused by copying the scripts from a windows machine to the unix (like) server. Running dos2unix on the files, from the host, should fix this problem.