【2019年10月版】docker-compose で立ち上げた MariaDBにつながらない・・・？

起動直後はつながらない・・・？

昨日の記事(【2019年10月版】Apollo + Sequelize で GraphQL やるなら TypeScript バッチリの TypeGraphQL がおすすめ!)で docker-compose にて MariaDB を使用しましたが、docker-compose up で立ち上げた mariadb は起動直後に接続できないことが時々ありました。

まずは起動してみる。

以下のような docker-compose.yml を作成して

docker-compose.yml

version : "3"
services:
  db:
    image: mariadb
    restart: always
    ports:
      - 3306:3306
    environment:
      - MYSQL_ROOT_PASSWORD=example
      - MYSQL_DATABASE=example
      - MYSQL_USER=example
      - MYSQL_PASSWORD=example

  adminer:
    image: adminer
    restart: always
    ports:
      - 8080:8080

これを以下のように立ち上げます。

$ sudo docker-compose up
...
adminer_1  | PHP 7.3.10 Development Server started at Fri Oct 25 02:17:08 2019
db_1       | Initializing database
db_1       | 
db_1       | 
db_1       | PLEASE REMEMBER TO SET A PASSWORD FOR THE MariaDB root USER !
db_1       | To do so, start the server, then issue the following commands:
db_1       | 
db_1       | '/usr/bin/mysqladmin' -u root password 'new-password'
db_1       | '/usr/bin/mysqladmin' -u root -h  password 'new-password'
db_1       | 
db_1       | Alternatively you can run:
db_1       | '/usr/bin/mysql_secure_installation'
db_1       | 
db_1       | which will also give you the option of removing the test
db_1       | databases and anonymous user created by default.  This is
db_1       | strongly recommended for production servers.
db_1       | 
db_1       | See the MariaDB Knowledgebase at http://mariadb.com/kb or the
db_1       | MySQL manual for more instructions.
db_1       | 
db_1       | Please report any problems at http://mariadb.org/jira
db_1       | 
db_1       | The latest information about MariaDB is available at http://mariadb.org/.
db_1       | You can find additional information about the MySQL part at:
db_1       | http://dev.mysql.com
db_1       | Consider joining MariaDB's strong and vibrant community:
db_1       | https://mariadb.org/get-involved/
db_1       | 
db_1       | Database initialized
db_1       | MySQL init process in progress...
db_1       | 2019-10-25  2:17:17 0 [Note] mysqld (mysqld 10.4.8-MariaDB-1:10.4.8+maria~bionic) starting as process 108 ...
db_1       | 2019-10-25  2:17:17 0 [Note] InnoDB: Using Linux native AIO
db_1       | 2019-10-25  2:17:17 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
db_1       | 2019-10-25  2:17:17 0 [Note] InnoDB: Uses event mutexes
db_1       | 2019-10-25  2:17:17 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
db_1       | 2019-10-25  2:17:17 0 [Note] InnoDB: Number of pools: 1
db_1       | 2019-10-25  2:17:17 0 [Note] InnoDB: Using SSE2 crc32 instructions
db_1       | 2019-10-25  2:17:17 0 [Note] mysqld: O_TMPFILE is not supported on /tmp (disabling future attempts)
db_1       | 2019-10-25  2:17:17 0 [Note] InnoDB: Initializing buffer pool, total size = 256M, instances = 1, chunk size = 128M
db_1       | 2019-10-25  2:17:17 0 [Note] InnoDB: Completed initialization of buffer pool
db_1       | 2019-10-25  2:17:17 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-10-25  2:17:17 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
db_1       | 2019-10-25  2:17:17 0 [Note] InnoDB: Creating shared tablespace for temporary tables
db_1       | 2019-10-25  2:17:17 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
db_1       | 2019-10-25  2:17:17 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
db_1       | 2019-10-25  2:17:17 0 [Note] InnoDB: Waiting for purge to start
db_1       | 2019-10-25  2:17:18 0 [Note] InnoDB: 10.4.8 started; log sequence number 139836; transaction id 21
db_1       | 2019-10-25  2:17:18 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
db_1       | 2019-10-25  2:17:18 0 [Note] Plugin 'FEEDBACK' is disabled.
db_1       | 2019-10-25  2:17:18 0 [Warning] 'user' entry 'root@efa12e87e1d9' ignored in --skip-name-resolve mode.
db_1       | 2019-10-25  2:17:18 0 [Warning] 'user' entry '@efa12e87e1d9' ignored in --skip-name-resolve mode.
db_1       | 2019-10-25  2:17:18 0 [Warning] 'proxies_priv' entry '@% root@efa12e87e1d9' ignored in --skip-name-resolve mode.
db_1       | 2019-10-25  2:17:18 0 [Note] InnoDB: Buffer pool(s) load completed at 191025  2:17:18
db_1       | 2019-10-25  2:17:18 0 [Note] Reading of all Master_info entries succeeded
db_1       | 2019-10-25  2:17:18 0 [Note] Added new Master_info '' to hash table
db_1       | 2019-10-25  2:17:18 0 [Note] mysqld: ready for connections.
db_1       | Version: '10.4.8-MariaDB-1:10.4.8+maria~bionic'  socket: '/var/run/mysqld/mysqld.sock'  port: 0  mariadb.org binary distribution
db_1       | Warning: Unable to load '/usr/share/zoneinfo/leap-seconds.list' as time zone. Skipping it.

起動直後、つながらない

で、 'http://localhost:8080' をブラウザから開き、Adminerにてログインしてみると・・・・

Connection refused ... 拒否されてしまいました。

ちなみに、わざと PostgreSQL で接続してみると・・・

host "db"(192.168.128.3) とメッセージがあるので IPアドレスの名前解決はちゃんと出来ているようです。

Dockerのネットーワークをチェックしてみる

ちなみにこの、IPアドレスが適切かどうかは以下の手順で確認できます。

まず、docker network ls でネットワークの一覧を出力します。

$ docker network ls
NETWORK ID          NAME                DRIVER              SCOPE
...
a8d04ad9a64a        XXXX_default        bridge              local
...

ここで、docker-compose up したフォルダ名+"_default"のネットワークが今、注目するべきネットワークとなります。

このネットーワークの詳細は以下のコマンドで出力できます。

$ docker network inspect XXXX_default
[
    {
        "Name": "test_default",
        "Id": "193e221a79c12f21e0f3375999363c8c578b4a1b65d7b59f774aa47e8733d7e2",
        "Created": "2019-10-25T11:17:04.226775261+09:00",
        "Scope": "local",
        "Driver": "bridge",
        "EnableIPv6": false,
        "IPAM": {
            "Driver": "default",
            "Options": null,
            "Config": [
                {
                    "Subnet": "192.168.128.0/20",
                    "Gateway": "192.168.128.1"
                }
            ]
        },
        "Internal": false,
        "Attachable": true,
        "Ingress": false,
        "ConfigFrom": {
            "Network": ""
        },
        "ConfigOnly": false,
        "Containers": {
            "614e09fc22482fb3a9d1d918e4d3d1cff2fc340adf37fbca960b33aa321bf2fb": {
                "Name": "XXXX_adminer_1",
                "EndpointID": "31c4df8dbdaf9e6c1dc625877b156b1e589ab2fb5ccba0e55465c630beeb5619",
                "MacAddress": "02:42:c0:a8:80:02",
                "IPv4Address": "192.168.128.2/20",
                "IPv6Address": ""
            },
            "efa12e87e1d9f0791a5f6309776e9d8f2c8ef172fa2d8d0b95832fb0ca5fd8c3": {
                "Name": "XXXX_db_1",
                "EndpointID": "05734ba9d54b2e839a51e63d7c6b7c742d6e3a154dcaecb4044e44fd5ffff844",
                "MacAddress": "02:42:c0:a8:80:03",
                "IPv4Address": "192.168.128.3/20",
                "IPv6Address": ""
            }
        },
        "Options": {},
        "Labels": {
            "com.docker.compose.network": "default",
            "com.docker.compose.project": "test",
            "com.docker.compose.version": "1.24.0"
        }
    }
]

で、XXXX_db_1 コンテナのIPアドレスは 192.168.128.3 が割り当てられており、上記のエラーメッセージで表示されたIPアドレスと一致します。つまり、名前解決はOKのようです。

MariaDB を直接、チェック

以下は MySQL での issue チケットになりますが、

• Host '172.18.0.1' is not allowed to connect to this MySQL server

こちらは"待ち受けているIPアドレスとユーザーの設定がうまくいかないと接続できないよね？"という話です。
今回は root でも接続できないので、ちょっとどうなのかな？という気がします。

ちなみに以下のコマンドで mariadb に直接、接続は可能です。

$ docker-compose exec db mariadb -p
Enter password: 
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 11
Server version: 10.4.8-MariaDB-1:10.4.8+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)]> 

ここでSQLなどは実行可能です。quit;で抜けれます。

コンテナ内部の環境変数をチェック

ついでにコンテナの内部のホスト名は以下のように envコマンドで確認できます。

$ docker-compose exec db env
PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
HOSTNAME=efa12e87e1d9
TERM=xterm
MYSQL_ROOT_PASSWORD=example
MYSQL_DATABASE=example
MYSQL_USER=example
MYSQL_PASSWORD=example
GOSU_VERSION=1.10
GPG_KEYS=177F4010FE56CA3336300305F1656F24C74CD1D8
MARIADB_MAJOR=10.4
MARIADB_VERSION=1:10.4.8+maria~bionic
HOME=/root

上記のHOSTNAME=efa12e87e1d9がそれです。efa12e87e1d9という名前でも接続できるはず、なのです。

ついでに MYSQL_XXXX の環境変数も設定されているので、docker-compose の変数設定が間違っていてログインできない・・・ということもなさそうです。

・・・勝手に再起動？？

などといろいろやっていると、MariaDBのログが流れて・・・

db_1       | 2019-10-25  2:23:57 10 [Warning] 'proxies_priv' entry '@% root@efa12e87e1d9' ignored in --skip-name-resolve mode.
db_1       | 
db_1       | 2019-10-25  2:23:57 0 [Note] mysqld (initiated by: unknown): Normal shutdown
db_1       | 2019-10-25  2:23:57 0 [Note] Event Scheduler: Purging the queue. 0 events
db_1       | 2019-10-25  2:23:57 0 [Note] InnoDB: FTS optimize thread exiting.
db_1       | 2019-10-25  2:23:57 0 [Note] InnoDB: Starting shutdown...
db_1       | 2019-10-25  2:23:57 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
db_1       | 2019-10-25  2:23:57 0 [Note] InnoDB: Buffer pool(s) dump completed at 191025  2:23:57
db_1       | 2019-10-25  2:23:59 0 [Note] InnoDB: Shutdown completed; log sequence number 20421527; transaction id 14852
db_1       | 2019-10-25  2:23:59 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
db_1       | 2019-10-25  2:23:59 0 [Note] mysqld: Shutdown complete
db_1       | 
db_1       | 
db_1       | MySQL init process done. Ready for start up.
db_1       | 
db_1       | 2019-10-25  2:23:59 0 [Note] mysqld (mysqld 10.4.8-MariaDB-1:10.4.8+maria~bionic) starting as process 1 ...
db_1       | 2019-10-25  2:23:59 0 [Note] InnoDB: Using Linux native AIO
db_1       | 2019-10-25  2:23:59 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
db_1       | 2019-10-25  2:23:59 0 [Note] InnoDB: Uses event mutexes
db_1       | 2019-10-25  2:23:59 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
db_1       | 2019-10-25  2:23:59 0 [Note] InnoDB: Number of pools: 1
db_1       | 2019-10-25  2:23:59 0 [Note] InnoDB: Using SSE2 crc32 instructions
db_1       | 2019-10-25  2:23:59 0 [Note] mysqld: O_TMPFILE is not supported on /tmp (disabling future attempts)
db_1       | 2019-10-25  2:23:59 0 [Note] InnoDB: Initializing buffer pool, total size = 256M, instances = 1, chunk size = 128M
db_1       | 2019-10-25  2:23:59 0 [Note] InnoDB: Completed initialization of buffer pool
db_1       | 2019-10-25  2:23:59 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-10-25  2:23:59 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
db_1       | 2019-10-25  2:23:59 0 [Note] InnoDB: Creating shared tablespace for temporary tables
db_1       | 2019-10-25  2:23:59 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
db_1       | 2019-10-25  2:23:59 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
db_1       | 2019-10-25  2:23:59 0 [Note] InnoDB: Waiting for purge to start
db_1       | 2019-10-25  2:23:59 0 [Note] InnoDB: 10.4.8 started; log sequence number 20421527; transaction id 14852
db_1       | 2019-10-25  2:23:59 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
db_1       | 2019-10-25  2:23:59 0 [Note] Plugin 'FEEDBACK' is disabled.
db_1       | 2019-10-25  2:23:59 0 [Note] Server socket created on IP: '::'.
db_1       | 2019-10-25  2:23:59 0 [Warning] 'proxies_priv' entry '@% root@efa12e87e1d9' ignored in --skip-name-resolve mode.
db_1       | 2019-10-25  2:23:59 0 [Note] InnoDB: Buffer pool(s) load completed at 191025  2:23:59
db_1       | 2019-10-25  2:23:59 0 [Note] Reading of all Master_info entries succeeded
db_1       | 2019-10-25  2:23:59 0 [Note] Added new Master_info '' to hash table
db_1       | 2019-10-25  2:23:59 0 [Note] mysqld: ready for connections.
db_1       | Version: '10.4.8-MariaDB-1:10.4.8+maria~bionic'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution

勝手に再起動したようですね・・・？

試しにログインしてみると・・・

・・・つながるじゃないか・・・？

実は手元の環境ではだいたい6分後にプロセスが再起動してつながるようになるのです。

たぶん、初回起動の初期化処理で6分ぐらいかかるのかな・・・？と思っています。

まとめ

というわけでdockerやdocker-compose で立ち上げたサービスにうまくつながらない場合のチェック方法をあれこれ並べてみました。

• ネットーワークの一覧 → docker network ls
• ネットーワークの詳細 → docker network inspect ネットーワークの名
• コンテナの環境変数取得 → docker-compose exec サービス名 env
• mariadbのクライアント直接起動 → docker-compose exec サービス名 mariadb -p

また、たいていの場合は docker-compose up -d でバックグラウンドに回してしまうと思いますが、問題があった場合は-dなしでログを垂れ流してみるのも手です。docker-compose logs でも見れますが。

上記の確認手順は今回の問題の解決にはなっていませんが、まぁ、そういうこともあるさ～ということで。。。