bgpkit / bgpkit-broker-backend

BGPKIT Broker backend services and API
MIT License
7 stars 0 forks source link

bgpkit-broker-updater | bash: line 1: /dev/tcp/postgres/5432: Connection refused #27

Closed egecemkirci closed 1 year ago

egecemkirci commented 1 year ago

Hi,

This is perhaps something obvious, but I tried to run the Quick Start deployment and got the following error. I directly run the docker-compose -f deployment/docker-compose.yml up right after cloning the repo. Is there a step that I miss, or something I misunderstand?

bgpkit-broker-postgres | postgresql 23:27:39.47
bgpkit-broker-postgres | postgresql 23:27:39.47 Welcome to the Bitnami postgresql container
bgpkit-broker-postgres | postgresql 23:27:39.47 Subscribe to project updates by watching https://github.com/bitnami/containers
bgpkit-broker-postgres | postgresql 23:27:39.48 Submit issues and feature requests at https://github.com/bitnami/containers/issues
bgpkit-broker-postgres | postgresql 23:27:39.48
bgpkit-broker-postgres | postgresql 23:27:39.51 INFO  ==> ** Starting PostgreSQL setup **
bgpkit-broker-postgres | postgresql 23:27:39.53 INFO  ==> Validating settings in POSTGRESQL_* env vars..
bgpkit-broker-postgres | postgresql 23:27:39.54 INFO  ==> Loading custom pre-init scripts...
bgpkit-broker-postgres | postgresql 23:27:39.55 INFO  ==> Initializing PostgreSQL database...
bgpkit-broker-postgres | postgresql 23:27:39.58 INFO  ==> pg_hba.conf file not detected. Generating it...
bgpkit-broker-postgres | postgresql 23:27:39.59 INFO  ==> Generating local authentication configuration
bgpkit-broker-postgres | postgresql 23:27:40.28 INFO  ==> Starting PostgreSQL in background...
bgpkit-broker-postgres | postgresql 23:27:40.49 INFO  ==> Creating user broker_user
bgpkit-broker-postgres | postgresql 23:27:40.51 INFO  ==> Granting access to "broker_user" to the database "broker"
bgpkit-broker-postgres | postgresql 23:27:40.54 INFO  ==> Setting ownership for the 'public' schema database "broker" to "broker_user"
bgpkit-broker-postgres | postgresql 23:27:40.58 INFO  ==> Configuring replication parameters
bgpkit-broker-postgres | postgresql 23:27:40.62 INFO  ==> Configuring synchronous_replication
bgpkit-broker-postgres | postgresql 23:27:40.63 INFO  ==> Configuring fsync
bgpkit-broker-postgres | postgresql 23:27:40.66 INFO  ==> Loading custom scripts...
bgpkit-broker-postgres | postgresql 23:27:40.67 INFO  ==> Loading user's custom files from /docker-entrypoint-initdb.d ...
bgpkit-broker-postgres | postgresql 23:27:40.67 INFO  ==> Starting PostgreSQL in background...
bgpkit-broker-postgres | start bootstrapping database
bgpkit-broker-postgres | downloading bootstrap database file
bgpkit-broker-postgres | bootstraping data
bgpkit-broker-updater | bash: connect: Connection refused
bgpkit-broker-updater | bash: line 1: /dev/tcp/postgres/5432: Connection refused
bgpkit-broker-api | bash: connect: Connection refused
bgpkit-broker-api | bash: line 1: /dev/tcp/postgres/5432: Connection refused
bgpkit-broker-updater | wait for postgres
bgpkit-broker-updater | bash: connect: Connection refused
bgpkit-broker-updater | bash: line 1: /dev/tcp/postgres/5432: Connection refused
bgpkit-broker-api | wait for postgres
bgpkit-broker-api | bash: connect: Connection refused
bgpkit-broker-api | bash: line 1: /dev/tcp/postgres/5432: Connection refused
digizeph commented 1 year ago

Hey @egecemkirci thanks for using bgpkit!

The messages you saw there were expected when you first boot up the docker containers. While the database is bootstrapping from a daily backup file, the updater and API will wait and check the Postgres 5432 ports every 30 seconds. When the database bootstrap is done, you should no longer see these messages.

Depending on the cores assigned to the system and the connection speed, the bootstrap process may take up to 1 hour to finish. This step is only needed one time for bootstrapping the historical data.

egecemkirci commented 1 year ago

Hi, @digizeph thanks for the fast response.

The build failed somewhere else (Step 16/18, to be specific) with the following error. This might be related (I still wanted to ask): https://stackoverflow.com/questions/34571711/cant-run-curl-command-inside-my-docker-container

Step 16/18 : RUN curl -fsSLO "$SUPERCRONIC_URL"  && echo "${SUPERCRONIC_SHA1SUM}  ${SUPERCRONIC}" | sha1sum -c -  && chmod +x "$SUPERCRONIC"  && mv "$SUPERCRONIC" "/usr/local/bin/${SUPERCRONIC}"  && ln -s "/usr/local/bin/${SUPERCRONIC}" /usr/local/bin/supercronic
 ---> Running in 6c7f4ce075c5
/bin/sh: 1: curl: not found
The command '/bin/sh -c curl -fsSLO "$SUPERCRONIC_URL"  && echo "${SUPERCRONIC_SHA1SUM}  ${SUPERCRONIC}" | sha1sum -c -  && chmod +x "$SUPERCRONIC"  && mv "$SUPERCRONIC" "/usr/local/bin/${SUPERCRONIC}"  && ln -s "/usr/local/bin/${SUPERCRONIC}" /usr/local/bin/supercronic' returned a non-zero code: 127
ERROR: Service 'updater' failed to build : Build failed
digizeph commented 1 year ago

This is strange. The use of supercronic is introduced in recent commits and with that, the curl command is definitely installed in the previous steps. https://github.com/bgpkit/bgpkit-broker-backend/blob/4f55847744b914e3054518b76fc087ab3fd1e35a/deployment/Dockerfile.updater#L24

I cannot reproduce this issue on my environment. Maybe it's a caching issue? Could you try docker-compose -f deployment/docker-compose.yml build --no-cache and see if it works after retry?

egecemkirci commented 1 year ago

Thank you for your feedback.

I started a clean VM, installed Docker, fetched the repository, and ran the docker-compose -f deployment/docker-compose.yml up command again.

At the moment, I am stuck with the following error messages every 5 minutes (this is iteration 23):

bgpkit-broker-updater | time="2022-11-27T20:50:00Z" level=error msg="error running command: exit status 101" iteration=23 job.command=/usr/local/bin/update.sh job.position=0 job.schedule="*/5 * * * *"
bgpkit-broker-updater | time="2022-11-27T20:55:00Z" level=info msg=starting iteration=24 job.command=/usr/local/bin/update.sh job.position=0 job.schedule="*/5 * * * *"
bgpkit-broker-updater | time="2022-11-27T20:55:00Z" level=info msg="thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Io(Custom { kind: Uncategorized, error: \"failed to lookup address information: Name or service not known\" })', /my_project/src/db/mod.rs:77:88" channel=stderr iteration=24 job.command=/usr/local/bin/update.sh job.position=0 job.schedule="*/5 * * * *"
bgpkit-broker-updater | time="2022-11-27T20:55:00Z" level=info msg="note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace" channel=stderr iteration=24 job.command=/usr/local/bin/update.sh job.position=0 job.schedule="*/5 * * * *"

I wonder if I missed anything in between, because it is also unclear to me how other components are supposed to interact with each other (e.g., there are repositories called bgpkit-broker and PyBGPKIT). Do they interact with a running instance of this docker container? I do not really see the workflow.

digizeph commented 1 year ago

@egecemkirci Thank you for the bug report. I believe the issue is fixed in 410f03a. To recap, the docker-compose file defined different service name and container name for postgres container, and thus causing other containers to use the wrong name for postgres services. Could you pull from the main branch and try again?

egecemkirci commented 1 year ago

Hi @digizeph I pulled the main repo and tried again. I get the following error:

bgpkit-broker-updater     | time="2022-11-28T11:25:00Z" level=info msg=starting iteration=3 job.command=/usr/local/bin/update.sh job.position=0 job.schedule="*/5 * * * *"
bgpkit-broker-updater     | time="2022-11-28T11:25:00Z" level=info msg="thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Io(Custom { kind: Uncategorized, error: \"failed to lookup address information: Name or service not known\" })', /my_project/src/db/mod.rs:77:88" channel=stderr iteration=3 job.command=/usr/local/bin/update.sh job.position=0 job.schedule="*/5 * * * *"
bgpkit-broker-updater     | time="2022-11-28T11:25:00Z" level=info msg="note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace" channel=stderr iteration=3 job.command=/usr/local/bin/update.sh job.position=0 job.schedule="*/5 * * * *"
bgpkit-broker-updater     | time="2022-11-28T11:25:00Z" level=error msg="error running command: exit status 101" iteration=3 job.command=/usr/local/bin/update.sh job.position=0 job.schedule="*/5 * * * *"
digizeph commented 1 year ago

I see the issue now. PR #29 should have fixed it. I have tested on a fresh Debian 11 box with Docker 20.10 and it works fine with refresh installation. @egecemkirci Let me know if this resolves your issue.

$ lsb_release --all
No LSB modules are available.
Distributor ID: Debian
Description:    Debian GNU/Linux 11 (bullseye)
Release:        11
Codename:       bullseye

$ docker version
Client: Docker Engine - Community
 Version:           20.10.21
 API version:       1.41
 Go version:        go1.18.7
 Git commit:        baeda1f
 Built:             Tue Oct 25 18:02:28 2022
 OS/Arch:           linux/amd64
 Context:           default
 Experimental:      true

Server: Docker Engine - Community
 Engine:
  Version:          20.10.21
  API version:      1.41 (minimum version 1.12)
  Go version:       go1.18.7
  Git commit:       3056208
  Built:            Tue Oct 25 18:00:19 2022
  OS/Arch:          linux/amd64
  Experimental:     false
 containerd:
  Version:          1.6.10
  GitCommit:        770bd0108c32f3fb5c73ae1264f7e503fe7b2661
 runc:
  Version:          1.1.4
  GitCommit:        v1.1.4-0-g5fd4c4d
 docker-init:
  Version:          0.19.0
  GitCommit:        de40ad0
egecemkirci commented 1 year ago

It seems to be working. I really appreciate the support. Thank you!