passbolt can't connect to the database with default docker image

[noraj]

What you did 📝

$ git clone https://github.com/passbolt/passbolt_docker
$ cd passbolt_docker
$ docker-compose -f docker-compose.yml up

What happened 💥 📋

$ docker-compose up --build                                                                                                                                                                                                                      
Starting passboltdocker_db_1 ...                                                                                                                                                                                                                                               
Starting passboltdocker_db_1 ... done
Starting passboltdocker_passbolt_1 ...
Starting passboltdocker_passbolt_1 ... done
Attaching to passboltdocker_db_1, passboltdocker_passbolt_1
db_1        | 2019-12-02 13:24:52+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server  started.
db_1        | 2019-12-02 13:24:53+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
db_1        | 2019-12-02 13:24:53+00:00 [Note] [Entrypoint]: Entrypoint script for MySQL Server  started.
db_1        | 2019-12-02 13:24:53 0 [Note] mysqld (mysqld 10.3.20-MariaDB-1:10.3.20+maria~bionic) starting as process 1 ...
db_1        | 2019-12-02 13:24:53 0 [Note] InnoDB: Using Linux native AIO
db_1        | 2019-12-02 13:24:53 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
db_1        | 2019-12-02 13:24:53 0 [Note] InnoDB: Uses event mutexes
db_1        | 2019-12-02 13:24:53 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
db_1        | 2019-12-02 13:24:53 0 [Note] InnoDB: Number of pools: 1
db_1        | 2019-12-02 13:24:53 0 [Note] InnoDB: Using SSE2 crc32 instructions
db_1        | 2019-12-02 13:24:53 0 [Note] InnoDB: Initializing buffer pool, total size = 256M, instances = 1, chunk size = 128M
db_1        | 2019-12-02 13:24:53 0 [Note] InnoDB: Completed initialization of buffer pool
db_1        | 2019-12-02 13:24:53 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().                                                                                                 
db_1        | 2019-12-02 13:24:54 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
db_1        | 2019-12-02 13:24:54 0 [Note] InnoDB: Creating shared tablespace for temporary tables
db_1        | 2019-12-02 13:24:54 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...                                                                                                                                    
db_1        | 2019-12-02 13:24:54 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
db_1        | 2019-12-02 13:24:54 0 [Note] InnoDB: Waiting for purge to start
db_1        | 2019-12-02 13:24:54 0 [Note] InnoDB: 10.3.20 started; log sequence number 8632508; transaction id 7576
db_1        | 2019-12-02 13:24:54 0 [Note] Plugin 'FEEDBACK' is disabled.
db_1        | 2019-12-02 13:24:54 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
db_1        | 2019-12-02 13:24:54 0 [Note] Server socket created on IP: '::'.
db_1        | 2019-12-02 13:24:54 0 [Warning] 'user' entry 'root@062b5bb0c212' ignored in --skip-name-resolve mode.
db_1        | 2019-12-02 13:24:54 0 [Warning] 'user' entry '@062b5bb0c212' ignored in --skip-name-resolve mode.
db_1        | 2019-12-02 13:24:54 0 [Warning] 'proxies_priv' entry '@% root@062b5bb0c212' ignored in --skip-name-resolve mode.
db_1        | 2019-12-02 13:24:54 0 [Note] Reading of all Master_info entries succeeded
db_1        | 2019-12-02 13:24:54 0 [Note] Added new Master_info '' to hash table
db_1        | 2019-12-02 13:24:54 0 [Note] mysqld: ready for connections.
db_1        | Version: '10.3.20-MariaDB-1:10.3.20+maria~bionic'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution
db_1        | 2019-12-02 13:24:54 0 [Note] InnoDB: Buffer pool(s) load completed at 191202 13:24:54
passbolt_1  | wait-for.sh: waiting 15 seconds for db:3306
passbolt_1  | wait-for.sh: db:3306 is available after 0 seconds
passbolt_1  | gpg: key 3ABE22782FE21DB1: "Passbolt default user <[email protected]>" not changed
passbolt_1  | gpg: Total number processed: 1
passbolt_1  | gpg:              unchanged: 1
passbolt_1  | gpg: key 3ABE22782FE21DB1: "Passbolt default user <[email protected]>" not changed
passbolt_1  | gpg: key 3ABE22782FE21DB1: secret key imported
passbolt_1  | gpg: Total number processed: 1
passbolt_1  | gpg:              unchanged: 1
passbolt_1  | gpg:       secret keys read: 1
passbolt_1  | gpg:  secret keys unchanged: 1
passbolt_1  |
passbolt_1  |      ____                  __          ____
passbolt_1  |     / __ \____  _____ ____/ /_  ____  / / /_
passbolt_1  |    / /_/ / __ `/ ___/ ___/ __ \/ __ \/ / __/
passbolt_1  |   / ____/ /_/ (__  |__  ) /_/ / /_/ / / /
passbolt_1  |  /_/    \__,_/____/____/_.___/\____/_/\__/
passbolt_1  |
passbolt_1  |  Open source password manager for teams
passbolt_1  | ---------------------------------------------------------------
passbolt_1  |
passbolt_1  | Running baseline checks, please wait...
passbolt_1  | Exception: SQLSTATE[HY000] [2006] MySQL server has gone away in [/var/www/passbolt/vendor/cakephp/cakephp/src/Database/Driver.php, line 92]                                                                                                                      
passbolt_1  |
passbolt_1  |      ____                  __          ____
passbolt_1  |     / __ \____  _____ ____/ /_  ____  / / /_
passbolt_1  |    / /_/ / __ `/ ___/ ___/ __ \/ __ \/ / __/
passbolt_1  |   / ____/ /_/ (__  |__  ) /_/ / /_/ / / /
passbolt_1  |  /_/    \__,_/____/____/_.___/\____/_/\__/
passbolt_1  |
passbolt_1  |  Open source password manager for teams
passbolt_1  | ---------------------------------------------------------------
passbolt_1  |  Running migration scripts.
passbolt_1  | ---------------------------------------------------------------
passbolt_1  | using migration paths
passbolt_1  |  - /var/www/passbolt/config/Migrations
passbolt_1  | using seed paths
passbolt_1  |  - /var/www/passbolt/config/Seeds
passbolt_1  | Exception: There was a problem connecting to the database: SQLSTATE[HY000] [2006] MySQL server has gone away in [/var/www/passbolt/vendor/robmorgan/phinx/src/Phinx/Db/Adapter/MysqlAdapter.php, line 127]                                                       
passboltdocker_passbolt_1 exited with code 1

The default configuration seems not to work, the app seems to fail to connect to the DB even with the default password which are identical in mysql.env and passbolt.env.

The same happens with the -dev.yml docker-compose.

What you expected to happen

Start.

Environment

The issue was reproduced on:

• openSUSE 15.1
  • docker 19.03.1_ce
  • docker-compose 1.17.0
• ArchLinux
  • docker 19.03.5-ce
  • docker-compose 1.25.0

[dlen]

Hi @noraj,

Thanks for reaching out! I can't reproduce your issue, could you confirm that after launching just the db container you can manually access it from the host?

On Linux and making use of the mysql.env credentials:

$ docker-compose up db
$ mysql -h 127.0.0.1 -u passbolt -p 
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 11
Server version: 10.3.20-MariaDB-1:10.3.20+maria~bionic mariadb.org binary distribution

Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MariaDB [(none)]> 

[noraj]

@dlen The issue I described was happening on openSUSE 15.1.
I reproduced the exact same behavior on ArchLinux.

And no, I can't connect to MariaDB:

$ mysql -h 127.0.0.1 -u passbolt -p
Enter password: 
ERROR 2013 (HY000): Lost connection to MySQL server at 'handshake: reading inital communication packet', system error: 11

[dlen]

Hi @noraj,

Does running a standalone mariadb container output the same result? For example:

$ docker run -ti -p 127.0.0.1:3306:3306 -e MYSQL_ROOT_PASSWORD=test -d mariadb:10.3
$ mysql -u root -h 127.0.0.1 -p 

[noraj]

@dlen Same error with the mariadb container alone.

EDIT: Ok now it works, it is just there is a long delay before the mariadb is available.

mysql -u root -h 127.0.0.1 -p                                               
Enter password: 
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 8
Server version: 10.3.20-MariaDB-1:10.3.20+maria~bionic mariadb.org binary distribution

Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MariaDB [(none)]> 

The issue is caused because passbolt container try to start when mariadb is still unavailable so it fails and crash while trying to connect. So wait-for.sh is not doing the job.

I guess you already followed https://docs.docker.com/compose/startup-order/

[dlen]

Yes, you are right, the default timeout is 15 seconds, more than that wait-for exits.

It is possible to tune the timeout on the docker-compose.yaml file modifying the command line:

command: ["/usr/bin/wait-for.sh", "-t", "0", "db:3306", "--", "/docker-entrypoint.sh"]

Thanks for the report I will add this timeout to the composer ASAP.

[nitishd]

I faced the same issue. The issue was with mariadb version, at that time mariadb:10.3 was pulling in 10.3.18 which has an issue reported here: MariaDB/mariadb-docker#262 . Using a previous version mariadb:10.3.16 worked. When the upstream fixes the issue the docker compose config should work as expected.

[noraj]

@nitishd ty for the explanation. @dlen ty for the fix.