Postgresql "cannot create sentinel: cannot create store: cannot create kv store"

bkniffler · October 24, 2022, 2:04pm

Again issues, looking different now (previous issues PG issues `backend 'bk_db' has no server available!`, FRA region - #4 by bkniffler). Just this morning, I followed the advice to update pg using fly image update.

Checks

  NAME | STATUS  | ALLOCATION | REGION | TYPE | LAST UPDATED | OUTPUT                                                                  
-------*---------*------------*--------*------*--------------*-------------------------------------------------------------------------
  pg   | passing | a154ef27   | fra    | HTTP | 3m2s ago     | HTTP GET http://172.19.3.146:5500/flycheck/pg: 200 OK Output: [✓]       
       |         |            |        |      |              |                                                                         
       |         |            |        |      |              | transactions: read/write (723.45µs)[✓]                                  
       |         |            |        |      |              |                                                                         
       |         |            |        |      |              | connections: 43 used, 3 reserved, 300 max (7.59ms)[✓]                   
       |         |            |        |      |              |                                                                         
       |         |            |        |      |              |                                                                         
  vm   | passing | a154ef27   | fra    | HTTP | 6m20s ago    | HTTP GET http://172.19.3.146:5500/flycheck/vm: 200 OK Output: [✓]       
       |         |            |        |      |              |                                                                         
       |         |            |        |      |              | checkDisk: 74.94 GB (38.2%) free space on /data/ (40.15µs)[✓]           
       |         |            |        |      |              |                                                                         
       |         |            |        |      |              | checkLoad: load averages: 1.04 1.67 1.51 (68.37µs)[✓]                   
       |         |            |        |      |              |                                                                         
       |         |            |        |      |              | memory: system spent 0s of the last 60s waiting on memory (29.85µs)[✓]  
       |         |            |        |      |              |                                                                         
       |         |            |        |      |              | cpu: system spent 4.14s of the last 60s waiting on cpu (21.06µs)[✓]     
       |         |            |        |      |              |                                                                         
       |         |            |        |      |              | io: system spent 78ms of the last 60s waiting on io (19.47µs)[✓]        
       |         |            |        |      |              |                                                                         
       |         |            |        |      |              |                                                                         
  role | passing | a154ef27   | fra    | HTTP | 3h10m ago    | leader[✓]                                                               
       |         |            |        |      |              |

Logs

$ fly logs -a finalytic-db
Waiting for logs...
2022-10-24T13:59:12.993 app[a154ef27] fra [info] sentinel | restarting in 3s [attempt 200]
2022-10-24T13:59:15.996 app[a154ef27] fra [info] sentinel | Running...
2022-10-24T13:59:16.069 app[a154ef27] fra [info] sentinel | 2022-10-24T13:59:16.068Z FATAL cmd/sentinel.go:2030 cannot create sentinel: cannot create store: cannot create kv store: Unexpected response code: 429 (Your IP is issuing too many concurrent connections, please rate limit your calls
2022-10-24T13:59:16.069 app[a154ef27] fra [info] sentinel | )
2022-10-24T13:59:16.071 app[a154ef27] fra [info] sentinel | exit status 1
2022-10-24T13:59:16.071 app[a154ef27] fra [info] sentinel | restarting in 3s [attempt 201]
2022-10-24T13:59:19.073 app[a154ef27] fra [info] sentinel | Running...
2022-10-24T13:59:19.096 app[a154ef27] fra [info] sentinel | 2022-10-24T13:59:19.095Z FATAL cmd/sentinel.go:2030 cannot create sentinel: cannot create store: cannot create kv store: Put "https://consul-fra-2.fly-shared.net/v1/catalog/register?wait=5000ms": read tcp [2605:4c40:197:5dea:0:1:8323:3]:47856->[2a09:8280:1::6:5ab1]:443: read: connection reset by peer
2022-10-24T13:59:19.097 app[a154ef27] fra [info] sentinel | exit status 1
2022-10-24T13:59:19.097 app[a154ef27] fra [info] sentinel | restarting in 3s [attempt 202]
2022-10-24T13:59:20.340 app[a154ef27] fra [info] keeper | Failed to create session finalytic-db-emkp298eko69orx5/23c312b842 [] Unexpected response code: 429 (Your IP is issuing too many concurrent connections, please rate limit your calls
2022-10-24T13:59:20.340 app[a154ef27] fra [info] keeper | )
2022-10-24T13:59:20.887 app[a154ef27] fra [info] keeper | 2022-10-24T13:59:20.884Z ERROR cmd/keeper.go:870 failed to update keeper info {"error": "cannot set or renew session for ttl, unable to operate on sessions"}
2022-10-24T13:59:21.746 app[a154ef27] fra [info] keeper | 2022-10-24T13:59:21.745Z ERROR cmd/keeper.go:1041 error retrieving cluster data {"error": "Unexpected response code: 429"}
2022-10-24T13:59:22.102 app[a154ef27] fra [info] sentinel | Running...
2022-10-24T13:59:22.215 app[a154ef27] fra [info] sentinel | 2022-10-24T13:59:22.214Z FATAL cmd/sentinel.go:2030 cannot create sentinel: cannot create store: cannot create kv store: Unexpected response code: 429 (Your IP is issuing too many concurrent connections, please rate limit your calls
2022-10-24T13:59:22.215 app[a154ef27] fra [info] sentinel | )
2022-10-24T13:59:22.216 app[a154ef27] fra [info] sentinel | exit status 1
2022-10-24T13:59:22.216 app[a154ef27] fra [info] sentinel | restarting in 3s [attempt 203]
2022-10-24T13:59:25.218 app[a154ef27] fra [info] sentinel | Running...
2022-10-24T13:59:25.242 app[a154ef27] fra [info] sentinel | 2022-10-24T13:59:25.241Z FATAL cmd/sentinel.go:2030 cannot create sentinel: cannot create store: cannot create kv store: Put "https://consul-fra-2.fly-shared.net/v1/catalog/register?wait=5000ms": read tcp [2605:4c40:197:5dea:0:1:8323:3]:47874->[2a09:8280:1::6:5ab1]:443: read: connection reset by peer
2022-10-24T13:59:25.243 app[a154ef27] fra [info] sentinel | exit status 1
2022-10-24T13:59:25.243 app[a154ef27] fra [info] sentinel | restarting in 3s [attempt 204]
2022-10-24T13:59:26.179 app[a154ef27] fra [info] keeper | 2022-10-24T13:59:26.178Z ERROR cmd/keeper.go:870 failed to update keeper info {"error": "Unexpected response code: 429 (Your IP is issuing too many concurrent connections, please rate limit your calls\n)"}
2022-10-24T13:59:28.245 app[a154ef27] fra [info] sentinel | Running...
2022-10-24T13:59:28.269 app[a154ef27] fra [info] sentinel | 2022-10-24T13:59:28.269Z FATAL cmd/sentinel.go:2030 cannot create sentinel: cannot create store: cannot create kv store: Put "https://consul-fra-2.fly-shared.net/v1/catalog/register?wait=5000ms": EOF
2022-10-24T13:59:28.272 app[a154ef27] fra [info] sentinel | exit status 1
2022-10-24T13:59:28.272 app[a154ef27] fra [info] sentinel | restarting in 3s [attempt 205]
2022-10-24T13:59:31.272 app[a154ef27] fra [info] sentinel | Running...
2022-10-24T13:59:31.293 app[a154ef27] fra [info] keeper | 2022-10-24T13:59:31.289Z ERROR cmd/keeper.go:870 failed to update keeper info {"error": "Unexpected response code: 429 (Your IP is issuing too many concurrent connections, please rate limit your calls\n)"}
2022-10-24T13:59:31.357 app[a154ef27] fra [info] sentinel | 2022-10-24T13:59:31.356Z FATAL cmd/sentinel.go:2030 cannot create sentinel: cannot create store: cannot create kv store: Unexpected response code: 429 (Your IP is issuing too many concurrent connections, please rate limit your calls
2022-10-24T13:59:31.357 app[a154ef27] fra [info] sentinel | )
2022-10-24T13:59:31.359 app[a154ef27] fra [info] sentinel | exit status 1
2022-10-24T13:59:31.359 app[a154ef27] fra [info] sentinel | restarting in 3s [attempt 206]
2022-10-24T13:59:32.221 app[a154ef27] fra [info] keeper | 2022-10-24T13:59:32.220Z ERROR cmd/keeper.go:1041 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": EOF"}
2022-10-24T13:59:34.362 app[a154ef27] fra [info] sentinel | Running...
2022-10-24T13:59:34.389 app[a154ef27] fra [info] sentinel | 2022-10-24T13:59:34.388Z FATAL cmd/sentinel.go:2030 cannot create sentinel: cannot create store: cannot create kv store: Put "https://consul-fra-2.fly-shared.net/v1/catalog/register?wait=5000ms": EOF
2022-10-24T13:59:34.390 app[a154ef27] fra [info] sentinel | exit status 1
2022-10-24T13:59:34.390 app[a154ef27] fra [info] sentinel | restarting in 3s [attempt 207]
2022-10-24T13:59:36.542 app[a154ef27] fra [info] keeper | 2022-10-24T13:59:36.542Z ERROR cmd/keeper.go:870 failed to update keeper info {"error": "Unexpected response code: 429 (Your IP is issuing too many concurrent connections, please rate limit your calls\n)"}
2022-10-24T13:59:37.391 app[a154ef27] fra [info] sentinel | Running...
2022-10-24T13:59:37.416 app[a154ef27] fra [info] sentinel | 2022-10-24T13:59:37.415Z FATAL cmd/sentinel.go:2030 cannot create sentinel: cannot create store: cannot create kv store: Put "https://consul-fra-2.fly-shared.net/v1/catalog/register?wait=5000ms": EOF
2022-10-24T13:59:37.417 app[a154ef27] fra [info] sentinel | exit status 1
2022-10-24T13:59:37.417 app[a154ef27] fra [info] sentinel | restarting in 3s [attempt 208]
2022-10-24T13:59:40.417 app[a154ef27] fra [info] sentinel | Running...
2022-10-24T13:59:40.463 app[a154ef27] fra [info] sentinel | 2022-10-24T13:59:40.462Z FATAL cmd/sentinel.go:2030 cannot create sentinel: cannot create store: cannot create kv store: Unexpected response code: 502 ()
2022-10-24T13:59:40.464 app[a154ef27] fra [info] sentinel | exit status 1
2022-10-24T13:59:40.464 app[a154ef27] fra [info] sentinel | restarting in 3s [attempt 209]
2022-10-24T13:59:41.753 app[a154ef27] fra [info] keeper | 2022-10-24T13:59:41.753Z ERROR cmd/keeper.go:870 failed to update keeper info {"error": "Unexpected response code: 429 (Your IP is issuing too many concurrent connections, please rate limit your calls\n)"}
2022-10-24T13:59:42.393 app[a154ef27] fra [info] keeper | 2022-10-24T13:59:42.393Z ERROR cmd/keeper.go:1041 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": EOF"}
2022-10-24T13:59:43.465 app[a154ef27] fra [info] sentinel | Running...
2022-10-24T13:59:43.598 app[a154ef27] fra [info] sentinel | 2022-10-24T13:59:43.598Z FATAL cmd/sentinel.go:2030 cannot create sentinel: cannot create store: cannot create kv store: Put "https://consul-fra-2.fly-shared.net/v1/catalog/register?wait=5000ms": EOF
2022-10-24T13:59:43.623 app[a154ef27] fra [info] sentinel | exit status 1
2022-10-24T13:59:43.623 app[a154ef27] fra [info] sentinel | restarting in 3s [attempt 210]
2022-10-24T13:59:46.626 app[a154ef27] fra [info] sentinel | Running...
2022-10-24T13:59:46.778 app[a154ef27] fra [info] sentinel | 2022-10-24T13:59:46.777Z FATAL cmd/sentinel.go:2030 cannot create sentinel: cannot create store: cannot create kv store: Unexpected response code: 429 (Your IP is issuing too many concurrent connections, please rate limit your calls
2022-10-24T13:59:46.778 app[a154ef27] fra [info] sentinel | )
2022-10-24T13:59:46.782 app[a154ef27] fra [info] sentinel | exit status 1
2022-10-24T13:59:46.782 app[a154ef27] fra [info] sentinel | restarting in 3s [attempt 211]
2022-10-24T13:59:49.783 app[a154ef27] fra [info] sentinel | Running...
2022-10-24T13:59:49.865 app[a154ef27] fra [info] sentinel | 2022-10-24T13:59:49.864Z FATAL cmd/sentinel.go:2030 cannot create sentinel: cannot create store: cannot create kv store: Unexpected response code: 429 (Your IP is issuing too many concurrent connections, please rate limit your calls
2022-10-24T13:59:49.865 app[a154ef27] fra [info] sentinel | )
2022-10-24T13:59:49.870 app[a154ef27] fra [info] sentinel | exit status 1
2022-10-24T13:59:49.870 app[a154ef27] fra [info] sentinel | restarting in 3s [attempt 212]
2022-10-24T13:59:52.873 app[a154ef27] fra [info] sentinel | Running...
2022-10-24T13:59:52.919 app[a154ef27] fra [info] sentinel | 2022-10-24T13:59:52.918Z FATAL cmd/sentinel.go:2030 cannot create sentinel: cannot create store: cannot create kv store: Put "https://consul-fra-2.fly-shared.net/v1/catalog/register?wait=5000ms": EOF
2022-10-24T13:59:52.920 app[a154ef27] fra [info] sentinel | exit status 1
2022-10-24T13:59:52.920 app[a154ef27] fra [info] sentinel | restarting in 3s [attempt 213]
2022-10-24T13:59:55.934 app[a154ef27] fra [info] sentinel | Running...
2022-10-24T13:59:56.803 app[a154ef27] fra [info] sentinel | 2022-10-24T13:59:56.803Z ERROR cmd/sentinel.go:1852 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": read tcp [2605:4c40:197:5dea:0:1:8323:3]:47920->[2a09:8280:1::6:5ab1]:443: read: connection reset by peer"}
2022-10-24T13:59:56.803 app[a154ef27] fra [info] sentinel | 2022-10-24T13:59:56.803Z ERROR cmd/sentinel.go:102 election loop error {"error": "Put \"https://consul-fra-2.fly-shared.net/v1/session/create?wait=5000ms\": read tcp [2605:4c40:197:5dea:0:1:8323:3]:47922->[2a09:8280:1::6:5ab1]:443: read: connection reset by peer"}
2022-10-24T14:00:01.809 app[a154ef27] fra [info] sentinel | 2022-10-24T14:00:01.806Z ERROR cmd/sentinel.go:1852 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": read tcp [2605:4c40:197:5dea:0:1:8323:3]:47924->[2a09:8280:1::6:5ab1]:443: read: connection reset by peer"}
2022-10-24T14:00:03.132 app[a154ef27] fra [info] keeper | 2022-10-24T14:00:03.127Z ERROR cmd/keeper.go:1041 error retrieving cluster data {"error": "Unexpected response code: 429"}
2022-10-24T14:00:06.808 app[a154ef27] fra [info] sentinel | 2022-10-24T14:00:06.806Z ERROR cmd/sentinel.go:102 election loop error {"error": "Put \"https://consul-fra-2.fly-shared.net/v1/session/create?wait=5000ms\": EOF"}
2022-10-24T14:00:06.810 app[a154ef27] fra [info] sentinel | 2022-10-24T14:00:06.809Z ERROR cmd/sentinel.go:1852 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": EOF"}
2022-10-24T14:00:10.264 app[a154ef27] fra [info] keeper | 2022-10-24T14:00:10.260Z ERROR cmd/keeper.go:870 failed to update keeper info {"error": "cannot set or renew session for ttl, unable to operate on sessions"}
2022-10-24T14:00:12.123 app[a154ef27] fra [info] sentinel | Failed to create session finalytic-db-emkp298eko69orx5/23c312b842 [] Unexpected response code: 429 (Your IP is issuing too many concurrent connections, please rate limit your calls
2022-10-24T14:00:12.123 app[a154ef27] fra [info] sentinel | )
2022-10-24T14:00:12.158 app[a154ef27] fra [info] sentinel | 2022-10-24T14:00:12.158Z ERROR cmd/sentinel.go:1889 cannot update sentinel info {"error": "cannot set or renew session for ttl, unable to operate on sessions"}
2022-10-24T14:00:13.468 app[a154ef27] fra [info] keeper | 2022-10-24T14:00:13.468Z ERROR cmd/keeper.go:1041 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": EOF"}
2022-10-24T14:00:15.292 app[a154ef27] fra [info] keeper | 2022-10-24T14:00:15.291Z ERROR cmd/keeper.go:870 failed to update keeper info {"error": "cannot set or renew session for ttl, unable to operate on sessions"}
2022-10-24T14:00:16.816 app[a154ef27] fra [info] sentinel | 2022-10-24T14:00:16.814Z ERROR cmd/sentinel.go:102 election loop error {"error": "Put \"https://consul-fra-2.fly-shared.net/v1/session/create?wait=5000ms\": read tcp [2605:4c40:197:5dea:0:1:8323:3]:47960->[2a09:8280:1::6:5ab1]:443: read: connection reset by peer"}
2022-10-24T14:00:17.162 app[a154ef27] fra [info] sentinel | 2022-10-24T14:00:17.160Z ERROR cmd/sentinel.go:1852 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": EOF"}
2022-10-24T14:00:18.476 app[a154ef27] fra [info] keeper | 2022-10-24T14:00:18.475Z ERROR cmd/keeper.go:1041 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": read tcp [2605:4c40:197:5dea:0:1:8323:3]:47968->[2a09:8280:1::6:5ab1]:443: read: connection reset by peer"}
2022-10-24T14:00:21.288 app[a154ef27] fra [info] keeper | 2022-10-24T14:00:21.256Z ERROR cmd/keeper.go:870 failed to update keeper info {"error": "Unexpected response code: 429 (Your IP is issuing too many concurrent connections, please rate limit your calls\n)"}
2022-10-24T14:00:22.270 app[a154ef27] fra [info] sentinel | 2022-10-24T14:00:22.265Z ERROR cmd/sentinel.go:1852 error retrieving cluster data {"error": "Unexpected response code: 429"}
2022-10-24T14:00:26.444 app[a154ef27] fra [info] keeper | 2022-10-24T14:00:26.444Z ERROR cmd/keeper.go:870 failed to update keeper info {"error": "Unexpected response code: 429 (Your IP is issuing too many concurrent connections, please rate limit your calls\n)"}
2022-10-24T14:00:26.827 app[a154ef27] fra [info] sentinel | 2022-10-24T14:00:26.826Z ERROR cmd/sentinel.go:102 election loop error {"error": "Put \"https://consul-fra-2.fly-shared.net/v1/session/create?wait=5000ms\": EOF"}
2022-10-24T14:00:27.274 app[a154ef27] fra [info] sentinel | 2022-10-24T14:00:27.273Z ERROR cmd/sentinel.go:1852 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": EOF"}
2022-10-24T14:00:28.796 app[a154ef27] fra [info] keeper | 2022-10-24T14:00:28.796Z ERROR cmd/keeper.go:1041 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": EOF"}
2022-10-24T14:00:32.333 app[a154ef27] fra [info] sentinel | 2022-10-24T14:00:32.331Z ERROR cmd/sentinel.go:1852 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": read tcp [2605:4c40:197:5dea:0:1:8323:3]:47994->[2a09:8280:1::6:5ab1]:443: read: connection reset by peer"}
2022-10-24T14:00:33.805 app[a154ef27] fra [info] keeper | 2022-10-24T14:00:33.804Z ERROR cmd/keeper.go:1041 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": read tcp [2605:4c40:197:5dea:0:1:8323:3]:47996->[2a09:8280:1::6:5ab1]:443: read: connection reset by peer"}
2022-10-24T14:00:37.363 app[a154ef27] fra [info] sentinel | 2022-10-24T14:00:37.354Z ERROR cmd/sentinel.go:102 election loop error {"error": "Unexpected response code: 429 (Your IP is issuing too many concurrent connections, please rate limit your calls\n)"}
2022-10-24T14:00:38.852 app[a154ef27] fra [info] keeper | 2022-10-24T14:00:38.851Z ERROR cmd/keeper.go:1041 error retrieving cluster data {"error": "Unexpected response code: 429"}
2022-10-24T14:00:43.223 app[a154ef27] fra [info] keeper | 2022-10-24T14:00:43.209Z ERROR cmd/keeper.go:870 failed to update keeper info {"error": "cannot set or renew session for ttl, unable to operate on sessions"}
2022-10-24T14:00:43.855 app[a154ef27] fra [info] keeper | 2022-10-24T14:00:43.855Z ERROR cmd/keeper.go:1041 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": read tcp [2605:4c40:197:5dea:0:1:8323:3]:48012->[2a09:8280:1::6:5ab1]:443: read: connection reset by peer"}
2022-10-24T14:00:44.114 app[a154ef27] fra [info] sentinel | 2022-10-24T14:00:44.111Z ERROR cmd/sentinel.go:1889 cannot update sentinel info {"error": "cannot set or renew session for ttl, unable to operate on sessions"}
2022-10-24T14:00:47.367 app[a154ef27] fra [info] sentinel | 2022-10-24T14:00:47.366Z ERROR cmd/sentinel.go:102 election loop error {"error": "Unexpected response code: 502 ()"}
2022-10-24T14:00:48.258 app[a154ef27] fra [info] keeper | 2022-10-24T14:00:48.253Z ERROR cmd/keeper.go:870 failed to update keeper info {"error": "cannot set or renew session for ttl, unable to operate on sessions"}
2022-10-24T14:00:49.865 app[a154ef27] fra [info] sentinel | 2022-10-24T14:00:49.863Z ERROR cmd/sentinel.go:1889 cannot update sentinel info {"error": "cannot set or renew session for ttl, unable to operate on sessions"}
2022-10-24T14:00:54.895 app[a154ef27] fra [info] sentinel | 2022-10-24T14:00:54.894Z ERROR cmd/sentinel.go:1852 error retrieving cluster data {"error": "Unexpected response code: 429"}
2022-10-24T14:00:57.390 app[a154ef27] fra [info] sentinel | 2022-10-24T14:00:57.389Z ERROR cmd/sentinel.go:102 election loop error {"error": "Unexpected response code: 429 (Your IP is issuing too many concurrent connections, please rate limit your calls\n)"}
2022-10-24T14:00:58.761 app[a154ef27] fra [info] keeper | 2022-10-24T14:00:58.759Z ERROR cmd/keeper.go:870 failed to update keeper info {"error": "Unexpected response code: 429 (Your IP is issuing too many concurrent connections, please rate limit your calls\n)"}
2022-10-24T14:00:59.243 app[a154ef27] fra [info] keeper | 2022-10-24T14:00:59.242Z ERROR cmd/keeper.go:1041 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": read tcp [2605:4c40:197:5dea:0:1:8323:3]:48052->[2a09:8280:1::6:5ab1]:443: read: connection reset by peer"}
2022-10-24T14:00:59.899 app[a154ef27] fra [info] sentinel | 2022-10-24T14:00:59.898Z ERROR cmd/sentinel.go:1852 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": EOF"}
2022-10-24T14:01:04.246 app[a154ef27] fra [info] keeper | 2022-10-24T14:01:04.245Z ERROR cmd/keeper.go:1041 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": read tcp [2605:4c40:197:5dea:0:1:8323:3]:48064->[2a09:8280:1::6:5ab1]:443: read: connection reset by peer"}
2022-10-24T14:01:04.904 app[a154ef27] fra [info] sentinel | 2022-10-24T14:01:04.903Z ERROR cmd/sentinel.go:1852 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": read tcp [2605:4c40:197:5dea:0:1:8323:3]:48066->[2a09:8280:1::6:5ab1]:443: read: connection reset by peer"}
2022-10-24T14:01:07.401 app[a154ef27] fra [info] sentinel | 2022-10-24T14:01:07.400Z ERROR cmd/sentinel.go:102 election loop error {"error": "Put \"https://consul-fra-2.fly-shared.net/v1/session/create?wait=5000ms\": EOF"}
2022-10-24T14:01:09.279 app[a154ef27] fra [info] keeper | 2022-10-24T14:01:09.278Z ERROR cmd/keeper.go:1041 error retrieving cluster data {"error": "Unexpected response code: 429"}
2022-10-24T14:01:10.149 app[a154ef27] fra [info] sentinel | 2022-10-24T14:01:10.148Z ERROR cmd/sentinel.go:1852 error retrieving cluster data {"error": "Unexpected response code: 429"}
2022-10-24T14:01:12.201 app[a154ef27] fra [info] keeper | 2022-10-24T14:01:12.200Z ERROR cmd/keeper.go:870 failed to update keeper info {"error": "Unexpected response code: 429 (Your IP is issuing too many concurrent connections, please rate limit your calls\n)"}
2022-10-24T14:01:14.284 app[a154ef27] fra [info] keeper | 2022-10-24T14:01:14.283Z ERROR cmd/keeper.go:1041 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": read tcp [2605:4c40:197:5dea:0:1:8323:3]:48082->[2a09:8280:1::6:5ab1]:443: read: connection reset by peer"}
2022-10-24T14:01:15.153 app[a154ef27] fra [info] sentinel | 2022-10-24T14:01:15.152Z ERROR cmd/sentinel.go:1852 error retrieving cluster data {"error": "Get \"https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms\": EOF"}
2022-10-24T14:01:17.370 app[a154ef27] fra [info] keeper | 2022-10-24T14:01:17.369Z ERROR cmd/keeper.go:870 failed to update keeper info {"error": "cannot set or renew session for ttl, unable to operate on sessions"}
2022-10-24T14:01:17.407 app[a154ef27] fra [info] sentinel | 2022-10-24T14:01:17.403Z ERROR cmd/sentinel.go:102 election loop error {"error": "Put \"https://consul-fra-2.fly-shared.net/v1/session/create?wait=5000ms\": EOF“}

bkniffler · October 24, 2022, 2:08pm

Restart doesn’t seem to help

2022-10-24T14:07:11.120 runner[6a497a07] fra [info] Starting instance
2022-10-24T14:07:19.262 runner[6a497a07] fra [info] Configuring virtual machine
2022-10-24T14:07:19.270 runner[6a497a07] fra [info] Pulling container image
2022-10-24T14:07:20.526 runner[6a497a07] fra [info] Unpacking image
2022-10-24T14:07:20.607 runner[6a497a07] fra [info] Preparing kernel init
2022-10-24T14:07:21.452 runner[6a497a07] fra [info] Setting up volume 'pg_data'
2022-10-24T14:07:21.889 runner[6a497a07] fra [info] Configuring firecracker
2022-10-24T14:07:22.005 runner[6a497a07] fra [info] Starting virtual machine
2022-10-24T14:07:22.967 app[6a497a07] fra [info] Starting init (commit: 249766e)...
2022-10-24T14:07:23.147 app[6a497a07] fra [info] Mounting /dev/vdc at /data w/ uid: 0, gid: 0 and chmod 0755
2022-10-24T14:07:23.181 app[6a497a07] fra [info] Preparing to run: `docker-entrypoint.sh start` as root
2022-10-24T14:07:23.262 app[6a497a07] fra [info] 2022/10/24 14:07:23 listening on [fdaa:0:58b5:a7b:c07e:1:8323:2]:22 (DNS: [fdaa::3]:53)
2022-10-24T14:07:23.670 app[6a497a07] fra [info] cluster spec filename /fly/cluster-spec.json
2022-10-24T14:07:23.671 app[6a497a07] fra [info] system memory: 10240mb vcpu count: 2
2022-10-24T14:07:23.671 app[6a497a07] fra [info] {
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "initMode": "existing",
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "existingConfig": {
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "keeperUID": "23c312b842"
2022-10-24T14:07:23.671 app[6a497a07] fra [info] },
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "pgParameters": {
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "archive_command": "if [ $ENABLE_WALG ]; then /usr/local/bin/wal-g wal-push \"%p\"; fi",
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "archive_mode": "on",
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "archive_timeout": "60",
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "effective_cache_size": "7680MB",
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "effective_io_concurrency": "200",
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "maintenance_work_mem": "512MB",
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "max_connections": "300",
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "max_parallel_workers": "8",
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "max_parallel_workers_per_gather": "2",
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "max_worker_processes": "8",
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "random_page_cost": "1.1",
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "shared_buffers": "2560MB",
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "wal_compression": "on",
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "work_mem": "160MB"
2022-10-24T14:07:23.671 app[6a497a07] fra [info] },
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "maxStandbysPerSender": 50,
2022-10-24T14:07:23.671 app[6a497a07] fra [info] "deadKeeperRemovalInterval": "1h"
2022-10-24T14:07:23.671 app[6a497a07] fra [info] }
2022-10-24T14:07:23.671 app[6a497a07] fra [info] generated new config
2022-10-24T14:07:23.674 app[6a497a07] fra [info] keeper | Running...
2022-10-24T14:07:23.676 app[6a497a07] fra [info] proxy | Running...
2022-10-24T14:07:23.679 app[6a497a07] fra [info] sentinel | Running...
2022-10-24T14:07:23.680 app[6a497a07] fra [info] exporter | Running...
2022-10-24T14:07:24.066 app[6a497a07] fra [info] exporter | INFO[0000] Starting Server: :9187 source="postgres_exporter.go:1837"
2022-10-24T14:07:24.099 app[6a497a07] fra [info] proxy | [WARNING] 296/140724 (557) : parsing [/fly/haproxy.cfg:38]: Missing LF on last line, file might have been truncated at position 96. This will become a hard error in HAProxy 2.3.
2022-10-24T14:07:24.125 app[6a497a07] fra [info] proxy | [NOTICE] 296/140724 (557) : New worker #1 (585) forked
2022-10-24T14:07:24.170 app[6a497a07] fra [info] proxy | [WARNING] 296/140724 (585) : bk_db/pg1 changed its IP from (none) to fdaa:0:58b5:a7b:c07e:1:8323:2 by flydns/dns1.
2022-10-24T14:07:24.170 app[6a497a07] fra [info] proxy | [WARNING] 296/140724 (585) : Server bk_db/pg1 ('fra.finalytic-db.internal') is UP/READY (resolves again).
2022-10-24T14:07:24.170 app[6a497a07] fra [info] proxy | [WARNING] 296/140724 (585) : Server bk_db/pg1 administratively READY thanks to valid DNS answer.
2022-10-24T14:07:24.417 app[6a497a07] fra [info] keeper | 2022-10-24T14:07:24.415Z FATAL cmd/keeper.go:2118 cannot create keeper: cannot create store: cannot create kv store: Put "https://consul-fra-2.fly-shared.net/v1/catalog/register?wait=5000ms": EOF
2022-10-24T14:07:24.422 app[6a497a07] fra [info] keeper | exit status 1
2022-10-24T14:07:24.422 app[6a497a07] fra [info] keeper | restarting in 5s [attempt 1]
2022-10-24T14:07:24.673 app[6a497a07] fra [info] checking stolon status
2022-10-24T14:07:24.960 app[6a497a07] fra [info] sentinel | 2022-10-24T14:07:24.958Z FATAL cmd/sentinel.go:2030 cannot create sentinel: cannot create election: cannot create kv store: Put "https://consul-fra-2.fly-shared.net/v1/catalog/register?wait=5000ms": EOF
2022-10-24T14:07:24.961 app[6a497a07] fra [info] sentinel | exit status 1
2022-10-24T14:07:24.961 app[6a497a07] fra [info] sentinel | restarting in 3s [attempt 1]
2022-10-24T14:07:25.573 app[6a497a07] fra [info] panic: error checking stolon status: cannot get cluster data: Get "https://consul-fra-2.fly-shared.net/v1/kv/finalytic-db-emkp298eko69orx5/finalytic-db/clusterdata?consistent=&wait=5000ms": EOF
2022-10-24T14:07:25.573 app[6a497a07] fra [info] : exit status 1
2022-10-24T14:07:25.573 app[6a497a07] fra [info] goroutine 21 [running]:
2022-10-24T14:07:25.573 app[6a497a07] fra [info] main.main.func2(0xc000114000, 0xc0000c0a80)
2022-10-24T14:07:25.573 app[6a497a07] fra [info] /go/src/github.com/fly-examples/postgres-ha/cmd/start/main.go:81 +0x72c
2022-10-24T14:07:25.573 app[6a497a07] fra [info] created by main.main
2022-10-24T14:07:25.573 app[6a497a07] fra [info] /go/src/github.com/fly-examples/postgres-ha/cmd/start/main.go:72 +0x43b

fermuch · October 24, 2022, 2:18pm

I got a similar error today. Turns out it was related to the volume not having enough space to perform a recovery.

You can see what happens with PG by entering ssh console and running:

su - stolon
postgres -D /data/postgres -c unix_socket_directories=/tmp

That should start postgres normally. If it fails, it’ll show you more than fly logs.

bkniffler · October 24, 2022, 2:23pm

Unfortunately, I can’t get into ssh since the instance can’t start (Error no instances found for …) @fermuch, but thanks for the advice

bkniffler · October 24, 2022, 2:28pm

Just increased the volume by 50gb, but no luck, still not starting…

shaun · October 24, 2022, 2:34pm

@bkniffler According to the logs you provided, it looks like you’re being rate limited.

Your IP is issuing too many concurrent connections, please rate limit your calls

I’m looking into this a bit further.

bkniffler · October 24, 2022, 2:59pm

Let me know if you find something please @shaun

shaun · October 24, 2022, 3:00pm

One of our consul clusters within fra went down and we are currently investigating the issue. Things should be recovering though, please let us know if you’re still seeing issues.

shaun · October 24, 2022, 3:50pm

@bkniffler How are things looking on your end?

bkniffler · October 24, 2022, 5:28pm

Sorry, had to quickly leave. Things went back to normal 5-10 minutes after your message, so all good again.

Topic		Replies	Views
Postgres having issues: `cannot create kv store` postgres , consul	5	175	December 14, 2023
PG issues `backend 'bk_db' has no server available!`, FRA region	5	496	October 24, 2022
postgres database not reachable	4	172	August 17, 2023
"Cannot create kv store" when creating a new Postgres Database Questions / Help	2	347	October 6, 2021
Issues creating database cluster in Singapore Questions / Help	5	343	April 18, 2021

Postgresql "cannot create sentinel: cannot create store: cannot create kv store"

Checks

Logs

Related Topics