Password authentication failed for user "postgres"

[joesixpack]

Just started seeing this from coordinator_db and it looks like other indexers are as well:

2022-04-27 03:38:34.036 UTC [1] LOG:  starting PostgreSQL 12.10 on x86_64-pc-linux-musl, compiled by gcc (Alpine 10.3.1_git20211027) 10.3.1 20211027, 64-bit
2022-04-27 03:38:34.036 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2022-04-27 03:38:34.036 UTC [1] LOG:  listening on IPv6 address "::", port 5432
2022-04-27 03:38:34.038 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2022-04-27 03:38:34.045 UTC [21] LOG:  database system was shut down at 2022-04-27 03:30:18 UTC
2022-04-27 03:38:34.046 UTC [1] LOG:  database system is ready to accept connections
2022-04-27 03:58:56.556 UTC [1933] LOG:  could not receive data from client: Connection reset by peer
2022-04-27 05:55:33.750 UTC [12475] FATAL:  unsupported frontend protocol 0.0: server supports 2.0 to 3.0
2022-04-27 05:55:33.937 UTC [12476] FATAL:  unsupported frontend protocol 255.255: server supports 2.0 to 3.0
2022-04-27 05:55:34.117 UTC [12477] FATAL:  no PostgreSQL user name specified in startup packet
2022-04-27 08:43:00.493 UTC [27688] LOG:  invalid length of startup packet
2022-04-27 10:33:16.518 UTC [37742] FATAL:  unsupported frontend protocol 16.0: server supports 2.0 to 3.0
2022-04-27 14:15:29.661 UTC [57996] FATAL:  unsupported frontend protocol 0.0: server supports 2.0 to 3.0
2022-04-27 14:15:29.983 UTC [57997] FATAL:  unsupported frontend protocol 255.255: server supports 2.0 to 3.0
2022-04-27 14:15:30.310 UTC [57998] FATAL:  no PostgreSQL user name specified in startup packet
2022-04-27 22:02:48.977 UTC [1612] LOG:  unexpected EOF on client connection with an open transaction
2022-04-27 23:14:56.314 UTC [100554] LOG:  unexpected EOF on client connection with an open transaction
2022-04-28 04:07:18.975 UTC [133472] FATAL:  unsupported frontend protocol 0.0: server supports 2.0 to 3.0
2022-04-28 04:07:19.164 UTC [133473] FATAL:  unsupported frontend protocol 255.255: server supports 2.0 to 3.0
2022-04-28 04:07:19.353 UTC [133474] FATAL:  no PostgreSQL user name specified in startup packet
2022-04-28 05:28:52.912 UTC [107093] LOG:  unexpected EOF on client connection with an open transaction
2022-04-28 06:17:14.256 UTC [140923] LOG:  unexpected EOF on client connection with an open transaction
2022-04-28 11:09:52.200 UTC [171673] LOG:  invalid length of startup packet
2022-04-28 13:00:11.726 UTC [181708] FATAL:  unsupported frontend protocol 16.0: server supports 2.0 to 3.0
2022-04-28 19:40:54.695 UTC [218205] LOG:  invalid length of startup packet
2022-04-28 20:07:28.941 UTC [220611] FATAL:  unsupported frontend protocol 0.0: server supports 2.0 to 3.0
2022-04-28 20:07:29.121 UTC [220612] FATAL:  unsupported frontend protocol 255.255: server supports 2.0 to 3.0
2022-04-28 20:07:29.301 UTC [220613] FATAL:  no PostgreSQL user name specified in startup packet
2022-04-28 23:34:23.703 UTC [239384] FATAL:  expected password response, got message type 0
2022-04-29 00:11:39.703 UTC [242758] FATAL:  unsupported frontend protocol 0.0: server supports 2.0 to 3.0
2022-04-29 00:11:39.899 UTC [242759] FATAL:  unsupported frontend protocol 255.255: server supports 2.0 to 3.0
2022-04-29 00:11:40.095 UTC [242760] FATAL:  no PostgreSQL user name specified in startup packet
2022-04-29 14:50:52.434 UTC [322509] FATAL:  unsupported frontend protocol 65363.19778: server supports 2.0 to 3.0
2022-04-29 19:48:40.209 UTC [349766] LOG:  invalid length of startup packet
2022-04-29 21:00:45.695 UTC [356358] FATAL:  expected password response, got message type 0
2022-04-29 22:01:02.891 UTC [361865] FATAL:  unsupported frontend protocol 16.0: server supports 2.0 to 3.0
2022-04-29 23:56:06.483 UTC [372359] FATAL:  unsupported frontend protocol 0.0: server supports 2.0 to 3.0
2022-04-29 23:56:06.509 UTC [372360] FATAL:  unsupported frontend protocol 255.255: server supports 2.0 to 3.0
2022-04-29 23:56:06.534 UTC [372361] FATAL:  no PostgreSQL user name specified in startup packet
2022-04-30 03:44:05.193 UTC [393081] FATAL:  password authentication failed for user "postgres"
2022-04-30 03:44:05.193 UTC [393081] DETAIL:  Password does not match for user "postgres".
        Connection matched pg_hba.conf line 99: "host all all all md5"
2022-04-30 03:44:11.243 UTC [393091] FATAL:  password authentication failed for user "postgres"
2022-04-30 03:44:11.243 UTC [393091] DETAIL:  Password does not match for user "postgres".
        Connection matched pg_hba.conf line 99: "host all all all md5"
2022-04-30 03:44:11.252 UTC [393090] FATAL:  password authentication failed for user "postgres"
2022-04-30 03:44:11.252 UTC [393090] DETAIL:  Password does not match for user "postgres".
        Connection matched pg_hba.conf line 99: "host all all all md5"
2022-04-30 03:44:11.255 UTC [393089] FATAL:  password authentication failed for user "postgres"
2022-04-30 03:44:11.255 UTC [393089] DETAIL:  Password does not match for user "postgres".
        Connection matched pg_hba.conf line 99: "host all all all md5"

From coordinator_service:

2022-04-30T03:40:16.236Z <transaction> INFO report project status: SUCCEED
2022-04-30T03:44:04.208Z <transaction> INFO report project status: PROCESSING | project QmSzPQ9f4U1GERvN1AxJ28xq9B5s4M72CPvotmmv1N2bN7 | time: 1651290228 | block height: 12473448
2022-04-30T03:44:45.539Z <transaction> INFO report project status: SUCCEED
2022-04-30T03:44:45.594Z <network> ERROR failed to update network: error: password authentication failed for user "postgres"
2022-04-30T03:44:45.594Z <network> INFO retry to send transactions
2022-04-30T05:11:59.325Z <nestjs> ERROR password authentication failed for user "postgres"
2022-04-30T05:16:59.380Z <nestjs> ERROR password authentication failed for user "postgres"

From one node container:

2022-04-30T02:18:41.732Z <fetch> INFO fetch block [12473414,12473416], total 3 blocks
2022-04-30T02:18:52.162Z <benchmark> INFO 0.36 bps, target: #12473419, current: #12473416, estimate time: 0 days 00 hours 00 mins
2022-04-30T02:19:07.163Z <benchmark> INFO NaN bps, target: #12473420, current: #12473416, estimate time: NaN days NaN hours NaN mins
2022-04-30T02:19:22.163Z <benchmark> INFO NaN bps, target: #12473423, current: #12473416, estimate time: NaN days NaN hours NaN mins
2022-04-30T02:19:37.162Z <benchmark> INFO NaN bps, target: #12473426, current: #12473416, estimate time: NaN days NaN hours NaN mins
2022-04-30T02:19:52.163Z <benchmark> INFO NaN bps, target: #12473429, current: #12473416, estimate time: NaN days NaN hours NaN mins
2022-04-30T02:20:07.163Z <benchmark> INFO NaN bps, target: #12473430, current: #12473416, estimate time: NaN days NaN hours NaN mins
2022-04-30T02:20:17.796Z <dictionary> WARN failed to fetch dictionary result Error: request to https://api.subquery.network/sq/subquery/kusama-dictionary failed, reason: read ECONNRESET
2022-04-30T02:20:20.978Z <fetch> WARN Dictionary indexed block is behind current indexing block height
2022-04-30T02:20:22.163Z <benchmark> INFO NaN bps, target: #12473431, current: #12473416, estimate time: NaN days NaN hours NaN mins
2022-04-30T02:20:24.799Z <fetch> WARN Dictionary indexed block is behind current indexing block height
2022-04-30T02:20:34.532Z <fetch> INFO fetch block [12473417,12473430], total 14 blocks
2022-04-30T02:20:34.914Z <fetch> INFO fetch block [12473431,12473434], total 4 blocks
2022-04-30T02:20:35.913Z <fetch> WARN Dictionary indexed block is behind current indexing block height
2022-04-30T02:20:37.163Z <benchmark> INFO 0.16 bps, target: #12473435, current: #12473434, estimate time: 0 days 00 hours 00 mins
2022-04-30T02:20:41.403Z <fetch> INFO fetch block [12473435,12473435], total 1 blocks
2022-04-30T02:20:52.163Z <benchmark> INFO 0.16 bps, target: #12473439, current: #12473435, estimate time: 0 days 00 hours 00 mins
2022-04-30T02:20:53.698Z <fetch> WARN Dictionary indexed block is behind current indexing block height
2022-04-30T02:21:06.229Z <fetch> INFO fetch block [12473436,12473439], total 4 blocks
2022-04-30T02:21:07.163Z <benchmark> INFO 0.16 bps, target: #12473439, current: #12473439, estimate time: 0 days 00 hours 00 mins
2022-04-30T02:21:17.452Z <fetch> WARN Dictionary indexed block is behind current indexing block height
2022-04-30T02:21:22.162Z <benchmark> INFO NaN bps, target: #12473442, current: #12473439, estimate time: NaN days NaN hours NaN mins
2022-04-30T02:21:24.588Z <fetch> INFO fetch block [12473441,12473442], total 2 blocks
2022-04-30T02:21:25.602Z <fetch> WARN Dictionary indexed block is behind current indexing block height
2022-04-30T02:21:31.235Z <fetch> INFO fetch block [12473443,12473443], total 1 blocks
2022-04-30T02:21:32.668Z <fetch> WARN Dictionary indexed block is behind current indexing block height
2022-04-30T02:21:37.163Z <benchmark> INFO 0.16 bps, target: #12473446, current: #12473443, estimate time: 0 days 00 hours 00 mins
2022-04-30T02:21:38.911Z <fetch> INFO fetch block [12473444,12473446], total 3 blocks
2022-04-30T02:21:39.740Z <fetch> WARN Dictionary indexed block is behind current indexing block height
2022-04-30T02:21:50.912Z <fetch> WARN Dictionary indexed block is behind current indexing block height
2022-04-30T02:21:52.163Z <benchmark> INFO 0.39 bps, target: #12473448, current: #12473446, estimate time: 0 days 00 hours 00 mins
2022-04-30T02:21:56.544Z <fetch> INFO fetch block [12473447,12473447], total 1 blocks
2022-04-30T02:21:56.780Z <fetch> INFO fetch block [12473448,12473448], total 1 blocks
2022-04-30T02:22:07.163Z <benchmark> INFO 0.11 bps, target: #12473449, current: #12473448, estimate time: 0 days 00 hours 00 mins
2022-04-30T02:22:22.162Z <benchmark> INFO NaN bps, target: #12473452, current: #12473448, estimate time: NaN days NaN hours NaN mins
2022-04-30T02:22:37.163Z <benchmark> INFO NaN bps, target: #12473455, current: #12473448, estimate time: NaN days NaN hours NaN mins
2022-04-30T02:22:52.162Z <benchmark> INFO NaN bps, target: #12473458, current: #12473448, estimate time: NaN days NaN hours NaN mins
2022-04-30T02:23:07.163Z <benchmark> INFO NaN bps, target: #12473458, current: #12473448, estimate time: NaN days NaN hours NaN mins
2022-04-30T02:23:22.163Z <benchmark> INFO NaN bps, target: #12473462, current: #12473448, estimate time: NaN days NaN hours NaN mins
2022-04-30T02:23:37.162Z <benchmark> INFO NaN bps, target: #12473464, current: #12473448, estimate time: NaN days NaN hours NaN mins

From the other node container:

2022-04-30T03:43:52.707Z <fetch> WARN Dictionary indexed block is behind current indexing block height
2022-04-30T03:43:53.445Z <fetch> INFO fetch block [10095558,10095560], total 3 blocks
2022-04-30T03:44:02.244Z <benchmark> INFO 0.32 bps, target: #10095560, current: #10095560, estimate time: 0 days 00 hours 00 mins
2022-04-30T03:44:03.713Z <fetch> WARN Dictionary indexed block is behind current indexing block height
2022-04-30T03:44:04.590Z <fetch> INFO fetch block [10095561,10095561], total 1 blocks
2022-04-30T03:44:08.675Z <fetch> WARN Dictionary indexed block is behind current indexing block height
2022-04-30T03:44:09.741Z <fetch> INFO fetch block [10095562,10095562], total 1 blocks
2022-04-30T03:44:17.244Z <benchmark> INFO 0.12 bps, target: #10095562, current: #10095562, estimate time: 0 days 00 hours 00 mins
2022-04-30T03:44:19.688Z <fetch> WARN Dictionary indexed block is behind current indexing block height
2022-04-30T03:44:20.237Z <fetch> INFO fetch block [10095563,10095564], total 2 blocks
2022-04-30T03:44:20.261Z <fetch> ERROR failed to index block at height 10095563  SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:44:21.964Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:44:24.967Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:44:27.970Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:44:30.972Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:44:33.974Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:44:36.976Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:44:38.644Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:44:41.940Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:44:44.942Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:44:47.943Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:44:50.944Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:44:53.947Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:44:55.663Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:44:58.666Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:45:01.667Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:45:04.670Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:45:07.672Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:45:10.675Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"
2022-04-30T03:45:12.378Z <db> ERROR Unable to connect to the database SequelizeConnectionError: password authentication failed for user "postgres"

From the other node's query container:

2022-04-30T03:19:39.138Z <express> INFO request completed
2022-04-30T03:24:38.070Z <express> INFO request completed
2022-04-30T03:29:40.470Z <express> INFO request completed
2022-04-30T03:34:37.474Z <express> INFO request completed
2022-04-30T03:39:40.892Z <express> INFO request completed
Failed to fetch indexer meta,  request to http://node_qmyr8xqgaxucxmp:3001/meta failed, reason: connect ECONNREFUSED 172.22.0.7:3001
Failed to fetch indexer health,  request to http://node_qmyr8xqgaxucxmp:3001/health failed, reason: connect ECONNREFUSED 172.22.0.7:3001
Failed to fetch indexer meta,  request to http://node_qmyr8xqgaxucxmp:3001/meta failed, reason: connect ECONNREFUSED 172.22.0.7:3001
Failed to fetch indexer health,  request to http://node_qmyr8xqgaxucxmp:3001/health failed, reason: connect ECONNREFUSED 172.22.0.7:3001
Failed to fetch indexer meta,  request to http://node_qmyr8xqgaxucxmp:3001/meta failed, reason: connect ECONNREFUSED 172.22.0.7:3001
Failed to fetch indexer health,  request to http://node_qmyr8xqgaxucxmp:3001/health failed, reason: connect ECONNREFUSED 172.22.0.7:3001
Failed to fetch indexer meta,  request to http://node_qmyr8xqgaxucxmp:3001/meta failed, reason: connect ECONNREFUSED 172.22.0.7:3001
Failed to fetch indexer health,  request to http://node_qmyr8xqgaxucxmp:3001/health failed, reason: connect ECONNREFUSED 172.22.0.7:3001
Failed to fetch indexer meta,  request to http://node_qmyr8xqgaxucxmp:3001/meta failed, reason: connect ECONNREFUSED 172.22.0.7:3001
Failed to fetch indexer health,  request to http://node_qmyr8xqgaxucxmp:3001/health failed, reason: connect ECONNREFUSED 172.22.0.7:3001

[joesixpack]

j@tucana:~/subquery-indexer$ docker-compose down
Removing network cooridnator-service
ERROR: error while removing network: network cooridnator-service id a36af3908db4c040e0ee49ae88747a57812086765a324c5fceba42f12ebdf424 has active endpoints

j@tucana:~/subquery-indexer$ docker stop query_qmyr8xqgaxucxmp
query_qmyr8xqgaxucxmp
j@tucana:~/subquery-indexer$ docker stop node_qmyr8xqgaxucxmp
node_qmyr8xqgaxucxmp
j@tucana:~/subquery-indexer$ docker stop query_qmszpq9f4u1gerv
query_qmszpq9f4u1gerv
j@tucana:~/subquery-indexer$ docker stop node_qmszpq9f4u1gerv
node_qmszpq9f4u1gerv
j@tucana:~/subquery-indexer$ docker-compose down
Removing network cooridnator-service
j@tucana:~/subquery-indexer$

After restarting:

j@tucana:~/subquery-indexer$ docker logs da1760016d8f --follow
2022-04-30T05:34:44.627Z <nestjs> INFO Starting Nest application...
2022-04-30T05:34:44.669Z <nestjs> INFO TypeOrmModule dependencies initialized
2022-04-30T05:34:44.669Z <nestjs> INFO ConfigureModule dependencies initialized
2022-04-30T05:34:44.669Z <nestjs> INFO AppModule dependencies initialized
2022-04-30T05:34:44.669Z <nestjs> INFO ServeStaticModule dependencies initialized
2022-04-30T05:34:44.669Z <nestjs> INFO GraphQLSchemaBuilderModule dependencies initialized
2022-04-30T05:34:44.670Z <nestjs> INFO GraphQLModule dependencies initialized
2022-04-30T05:34:44.674Z <nestjs> ERROR Unable to connect to the database. Retrying (1)...
2022-04-30T05:34:47.681Z <nestjs> ERROR Unable to connect to the database. Retrying (2)...
2022-04-30T05:34:50.686Z <nestjs> ERROR Unable to connect to the database. Retrying (3)...
2022-04-30T05:34:53.688Z <nestjs> ERROR Unable to connect to the database. Retrying (4)...
2022-04-30T05:34:56.694Z <nestjs> ERROR Unable to connect to the database. Retrying (5)...
2022-04-30T05:34:59.699Z <nestjs> ERROR Unable to connect to the database. Retrying (6)...
2022-04-30T05:35:02.702Z <nestjs> ERROR Unable to connect to the database. Retrying (7)...
2022-04-30T05:35:05.708Z <nestjs> ERROR Unable to connect to the database. Retrying (8)...
2022-04-30T05:35:08.714Z <nestjs> ERROR Unable to connect to the database. Retrying (9)...
2022-04-30T05:35:08.714Z <nestjs> ERROR password authentication failed for user "postgres"
2022-04-30T05:35:10.163Z <nestjs> INFO Starting Nest application...

[joesixpack]

For those searching this issue, you need to install a Docker-specific firewall to prevent miscreants changing the postgres password as Docker containers ignore local system firewalls, i.e. are wide open.

[ianhe8x]

That's the problem, if the postgres port isn't protected, your db will be scanned out and altered. In the tutorial we use security group rather than local firewall so didn't hit your problem.

[joesixpack]

I'm currently using this: https://github.com/chaifeng/ufw-docker

However, its far from ideal as it won't detect any IP changes when containers are stopped, removed and recreated (possibly restarted -- haven't checked). So the rules need to be re-added each time. There is a better approach and possibly it could be PRed into an updated docker-compose later on if such a repository is opened.

[joesixpack]

Updating Docker will do it as well.