Corteza Server can not connect db 2021.9

hello,

I followed instructions here Multi-image MySQL :: Corteza Docs
I have identical docker-compose.yaml and .env files.

When I run docker-compose up -d the database server is started and healthy but Corteza does not start and hangs in an unhealthy status.

$ docker-compose ps
Name Command State Ports

corteza-prod_db_1 /docker-entrypoint.sh mysqld Up (healthy) 3306/tcp, 33060/tcp
corteza-prod_server_1 ./bin/corteza-server serve-api Up (unhealthy) 80/tcp

The logs are like this:
{“level”:“warn”,“ts”:1638831934.8287904,“logger”:“store.rdbms”,“msg”:“could not connect to the database”,“error”:“Error 1045: Access denied for user ‘dbuser’@‘192.168.208.3’ (using password: YES)”,“try”:59,“delay”:10}

I can connect to the database using mysql -u dbuser -pdbpass from within the db container.

thanks

Hi @uli

Did you change username or password for the db during or after the setup?
It’s kinda hard to believe that example configs fail on this step – must be something else.

Apologies but – could it be that these are old log entries from the startup when db was actually lagging behind and Corteza could not connect to it?

How about restarting the server container now (and keeping the db running)?

Hello @darh

I did not change anything in docker-compose.yaml, neither in .env

This is how the database is set up in docker-compose.yaml:
MYSQL_DATABASE: dbname
MYSQL_USER: dbuser
MYSQL_PASSWORD: dbpass

get the random generated password by running: docker-compose logs db | grep “GENERATED ROOT PASSWORD”

MYSQL_RANDOM_ROOT_PASSWORD: random

and in .env:
DB_DSN=dbuser:dbpass@tcp(db:3306)/dbname?collation=utf8mb4_general_ci

Also, I ran the startup in sequence and checked for the db to be up and running prior to the start of the server:

$ docker-compose up -d db

Creating corteza-prod_db_1 … done

$ docker logs 65d4a819b7ba

2021-12-07T08:51:32.318146Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.26-16) starting as process 1

2021-12-07T08:51:32.326020Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.

2021-12-07T08:51:34.422911Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.

2021-12-07T08:51:35.207634Z 0 [Warning] [MY-013746] [Server] A deprecated TLS version TLSv1 is enabled for channel mysql_main

2021-12-07T08:51:35.207739Z 0 [Warning] [MY-013746] [Server] A deprecated TLS version TLSv1.1 is enabled for channel mysql_main

2021-12-07T08:51:35.208791Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.

2021-12-07T08:51:35.208933Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.

2021-12-07T08:51:35.296362Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: ‘::’ port: 33060, socket: /var/lib/mysql/mysqlx.sock

2021-12-07T08:51:35.296597Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: ‘8.0.26-16’ socket: ‘/var/lib/mysql/mysql.sock’ port: 3306 Percona Server (GPL), Release 16, Revision 3d64165.

uli@exeggutor:~/corteza-prod$ docker logs 65d4a819b7ba > db.log

2021-12-07T08:51:32.318146Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.26-16) starting as process 1

2021-12-07T08:51:32.326020Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.

2021-12-07T08:51:34.422911Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.

2021-12-07T08:51:35.207634Z 0 [Warning] [MY-013746] [Server] A deprecated TLS version TLSv1 is enabled for channel mysql_main

2021-12-07T08:51:35.207739Z 0 [Warning] [MY-013746] [Server] A deprecated TLS version TLSv1.1 is enabled for channel mysql_main

2021-12-07T08:51:35.208791Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.

2021-12-07T08:51:35.208933Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.

2021-12-07T08:51:35.296362Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: ‘::’ port: 33060, socket: /var/lib/mysql/mysqlx.sock

2021-12-07T08:51:35.296597Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: ‘8.0.26-16’ socket: ‘/var/lib/mysql/mysql.sock’ port: 3306 Percona Server (GPL), Release 16, Revision 3d64165.

$ docker-compose up -d server

corteza-prod_db_1 is up-to-date

Creating corteza-prod_server_1 … done

$ docker logs 3480ab35a14c

{“level”:“warn”,“ts”:1638867218.5143187,“logger”:“store.rdbms”,“msg”:“could not connect to the database”,“error”:“Error 1045: Access denied for user ‘dbuser’@‘192.168.224.3’ (using password: YES)”,“try”:1,“delay”:10}

{“level”:“warn”,“ts”:1638867228.5273678,“logger”:“store.rdbms”,“msg”:“could not connect to the database”,“error”:“Error 1045: Access denied for user ‘dbuser’@‘192.168.224.3’ (using password: YES)”,“try”:2,“delay”:10}

{“level”:“warn”,“ts”:1638867238.5300703,“logger”:“store.rdbms”,“msg”:“could not connect to the database”,“error”:“Error 1045: Access denied for user ‘dbuser’@‘192.168.224.3’ (using password: YES)”,“try”:3,“delay”:10}

{“level”:“warn”,“ts”:1638867248.5410929,“logger”:“store.rdbms”,“msg”:“could not connect to the database”,“error”:“Error 1045: Access denied for user ‘dbuser’@‘192.168.224.3’ (using password: YES)”,“try”:4,“delay”:10}

{“level”:“warn”,“ts”:1638867258.544171,“logger”:“store.rdbms”,“msg”:“could not connect to the database”,“error”:“Error 1045: Access denied for user ‘dbuser’@‘192.168.224.3’ (using password: YES)”,“try”:5,“delay”:10}

{“level”:“warn”,“ts”:1638867268.5554817,“logger”:“store.rdbms”,“msg”:“could not connect to the database”,“error”:“Error 1045: Access denied for user ‘dbuser’@‘192.168.224.3’ (using password: YES)”,“try”:6,“delay”:10}

{“level”:“warn”,“ts”:1638867278.5664449,“logger”:“store.rdbms”,“msg”:“could not connect to the database”,“error”:“Error 1045: Access denied for user ‘dbuser’@‘192.168.224.3’ (using password: YES)”,“try”:7,“delay”:10}

{“level”:“warn”,“ts”:1638867288.5781517,“logger”:“store.rdbms”,“msg”:“could not connect to the database”,“error”:“Error 1045: Access denied for user ‘dbuser’@‘192.168.224.3’ (using password: YES)”,“try”:8,“delay”:10}

{“level”:“warn”,“ts”:1638867298.5896838,“logger”:“store.rdbms”,“msg”:“could not connect to the database”,“error”:“Error 1045: Access denied for user ‘dbuser’@‘192.168.224.3’ (using password: YES)”,“try”:9,“delay”:10}

{“level”:“warn”,“ts”:1638867308.5972257,“logger”:“store.rdbms”,“msg”:“could not connect to the database”,“error”:“Error 1045: Access denied for user ‘dbuser’@‘192.168.224.3’ (using password: YES)”,“try”:10,“delay”:10}

{“level”:“warn”,“ts”:1638867318.6053972,“logger”:“store.rdbms”,“msg”:“could not connect to the database”,“error”:“Error 1045: Access denied for user ‘dbuser’@‘192.168.224.3’ (using password: YES)”,“try”:11,“delay”:10}

{“level”:“warn”,“ts”:1638867328.6167939,“logger”:“store.rdbms”,“msg”:“could not connect to the database”,“error”:“Error 1045: Access denied for user ‘dbuser’@‘192.168.224.3’ (using password: YES)”,“try”:12,“delay”:10}

{“level”:“warn”,“ts”:1638867338.6207387,“logger”:“store.rdbms”,“msg”:“could not connect to the database”,“error”:“Error 1045: Access denied for user ‘dbuser’@‘192.168.224.3’ (using password: YES)”,“try”:13,“delay”:10}

$ docker-compose ps
Name Command State Ports

corteza-prod_db_1 /docker-entrypoint.sh mysqld Up (healthy) 3306/tcp, 33060/tcp
corteza-prod_server_1 ./bin/corteza-server serve-api Up (unhealthy) 80/tcp

I wonder why the connection to the DB is denied.

When I exec into the db container and try connect it does not work either:

bash-4.4$ mysql -u dbuser -pdbpass
mysql: [Warning] Using a password on the command line interface can be insecure.
ERROR 1045 (28000): Access denied for user ‘dbuser’@‘localhost’ (using password: YES)

any ideas?

Thanks for your help. Uli

Meanwhile I re-created the entire setup with postgres for the database. Same result. The corteza container starts up and becomes unhealty. In the log it says that the database refused the connect.

{“level”:“warn”,“ts”:1638961826.7574239,“logger”:“store.rdbms”,“msg”:“could not connect to the database”,“error”:“dial tcp 172.20.0.2:5432: connect: connection refused”,“try”:1,“delay”:10}

I installed ping and psql in the container and was able to ping the database server and able to connect to the database using psql.

With this, I am still unable to run and test Corteza.

@uli Unfortunately there is not enough information for me to help you from the Corteza’s point of view.

Please double check all your usernames, passwords, hostnames.
Make sure they are properly set BEFORE you do the initial run of the db containers. If you change them afterwards you’ll have to do some manual changes (on the db end) to change the username or password.

Thanks again.
I decided to start over all again.
I created a new VM with the latest version of Ubuntu Server 20.04.03 LTS and did all updates.
From then, I followed all steps in this video: How to set up a production instance of Corteza - YouTube.
I made the changes in the .env file to reflect my hostname and domain. Also I created a new JWT Secret. I did not make any other changes.
The result is exactly the same.

uli@jolteon:~/corteza-production$ docker ps
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
0982646f0f11 cortezaproject/corteza:2021.9 “./bin/corteza-serve…” About a minute ago Up About a minute (health: starting) 80/tcp corteza-production_server_1
8c132c4629d5 postgres:13 “docker-entrypoint.s…” 2 minutes ago Up About a minute (healthy) 5432/tcp corteza-production_db_1
f2fabbf82383 jrcs/letsencrypt-nginx-proxy-companion “/bin/bash /app/entr…” 19 minutes ago Up 19 minutes nginx-letsencrypt
8c88b9e20fbe jwilder/nginx-proxy “/app/docker-entrypo…” 19 minutes ago Up 19 minutes 0.0.0.0:80->80/tcp, :::80->80/tcp, 0.0.0.0:443->443/tcp, :::443->443/tcp nginx-proxy
uli@jolteon:~/corteza-production$ docker logs 0982646f0f11
{“level”:“warn”,“ts”:1639520114.9136992,“logger”:“store.rdbms”,“msg”:“could not connect to the database”,“error”:“dial tcp 172.20.0.2:5432: connect: connection refused”,“try”:1,“delay”:10}
uli@jolteon:~/corteza-production$

I am out of options, I guess.

@uli not long ago I had to set up some containers locally and these configs did the trick for me – https://gist.github.com/tjerman/05c7aa854755c6ba5a4530d6155ab5eb

Depending on what log level you are using, the final successful log messages (connected to db, provisioned, …) may not show so the last message would be that it couldn’t connect to the DB.

If that still doesn’t work, what do you see if you add some more logging docs ref?

your config file are working
thanks for helping

1 Like

Awesome; just make sure to change the version to latest (current latest is 2021.9.5, my configs are from a few months back), change the DB credentials and set a JWT secret for when you deploy to a server.

1 Like

Thank you @tjerman It is exactly that.
In .env, I had 2021.9 and when I changed it to 2021.9.3 everything worked.

2 Likes