LoginSignup
takapan228
@takapan228

Are you sure you want to delete the question?

Leaving a resolved question undeleted may help others!

dockerにおいてmysql接続に対するAccess deniedなどが発生し、docker コンテナが立ち上がらない

Q&AClosed
MySQLDockerEtherpad

解決したいこと

dockerやnginxのリバースプロキシ、letsencryptを用いて構築しているUbuntuサーバーを再起動後、etherpadのdockerコンテナを立ち上げるとERROR: Problem while initalizing the databaseや Error: ER_ACCESS_DENIED_ERROR: Access denied for user 'etherpad'@'172.24.0.3' (using password: YES)が出てコンテナを立ち上げることができません。
恐らくetherpadコンテナと同じネットワークに所属しているMySQLのコンテナが悪さをしていると考えていますが、実際にそうなのか?、またそうだとしても原因がわかりません。
どなたがインシデントの原因や解消方法がわかる方がいらっしゃいましたらご教授いただけますと幸いです。

サーバーの環境

OS Ubuntu20.04
docker snapでインストール 20.10.24

エラーの内容

docker compose upしてもetherpad_etherpadコンテナが立ち上がらない

当該するソースコード

docker-compose.yml
環境変数は、.envファイルから取得しています。

version: '3.8'

services: 
  etherpad: 
    image: etherpad/etherpad:latest
    container_name: etherpad_etherpad
    restart: always
    volumes:
      - etherpad:/opt/etherpad-lite
    environment:
      - VIRTUAL_HOST=etherpad
      - ADMIN_PASSWORD=${ETHERPAD_ADMIN_PASSWORD}
      - USER_PASSWORD=${ETHERPAD_USER_PASSWORD}
      - DB_TYPE=mysql
      - DB_HOST=db
      - DB_PORT=3306
      - DB_NAME=${MYSQL_DATABASE}
      - DB_USER=${MYSQL_USER}
      - DB_PASS=${MYSQL_PASSWORD}
      - DB_CHARSET=xxxxxx
      - SKIN_VARIANTS=light-toolbar super-dark-background super-light-editor full-width-editor
      - REQUIRE_AUTHENTICATION=true
      - TZ=Asia/Tokyo
    networks:
      - proxy-tier
      - default
    depends_on:
      - db
    healthcheck:
      disable: true  # disable any default healthcheck set by the image
  
  db:
    image: mariadb:latest
    container_name: etherpad_db
    command: --transaction-isolation=READ-COMMITTED --binlog-format=ROW 
    restart: always
    volumes:
      - db:/var/lib/mysql
    environment:
      - MYSQL_ROOT_PASSWORD=${MYSQL_ROOT_PASSWORD}
      - MYSQL_DATABASE=${MYSQL_DATABASE}
      - MYSQL_USER=${MYSQL_USER}
      - MYSQL_PASSWORD=${MYSQL_PASSWORD}
      - TZ=Asia/Tokyo


volumes:
  db:
    name: etherpad_db
  etherpad:
    name: etherpad_etherpad


networks:
  proxy-tier:
    name: proxy-network

コマンド実行結果

docker compose upのエラーを見るとetherpad_etherpadコンテナでProblem while initalizing the databaseエラーが発生しています。またエラー前後のアクセスが禁止されていることがわかります。このアクセスの禁止もエラーの原因に繋がりそうですが、なぜ禁止されているかはわからないです。

docker compose up
出力結果 (一部)

etherpad_db        | 2023-06-09 14:10:07+09:00 [Note] [Entrypoint]: Entrypoint script for MariaDB Server 1:10.6.5+maria~focal started.
etherpad_db        | 2023-06-09 14:10:08+09:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
etherpad_db        | 2023-06-09 14:10:08+09:00 [Note] [Entrypoint]: Entrypoint script for MariaDB Server 1:10.6.5+maria~focal started.
etherpad_db        | 2023-06-09 14:10:08 0 [Note] mysqld (server 10.6.5-MariaDB-1:10.6.5+maria~focal) starting as process 1 ...
etherpad_db        | 2023-06-09 14:10:08 0 [Warning] You need to use --log-bin to make --binlog-format work.
etherpad_db        | 2023-06-09 14:10:08で 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
etherpad_db        | 2023-06-09 14:10:08 0 [Note] InnoDB: Number of pools: 1
etherpad_db        | 2023-06-09 14:10:08 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
etherpad_db        | 2023-06-09 14:10:08 0 [Note] mysqld: O_TMPFILE is not supported on /tmp (disabling future attempts)
etherpad_db        | 2023-06-09 14:10:08 0 [Note] InnoDB: Using Linux native AIO
etherpad_db        | 2023-06-09 14:10:08 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
etherpad_db        | 2023-06-09 14:10:08 0 [Note] InnoDB: Completed initialization of buffer pool
etherpad_db        | 2023-06-09 14:10:08 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=1340015515,1340015515
etherpad_db        | 2023-06-09 14:10:09 0 [Note] InnoDB: 128 rollback segments are active.
etherpad_db        | 2023-06-09 14:10:09 0 [Note] InnoDB: Removed temporary tablespace data file: "./ibtmp1"
etherpad_db        | 2023-06-09 14:10:09 0 [Note] InnoDB: Creating shared tablespace for temporary tables
etherpad_db        | 2023-06-09 14:10:09 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
etherpad_db        | 2023-06-09 14:10:09 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
etherpad_db        | 2023-06-09 14:10:09 0 [Note] InnoDB: 10.6.5 started; log sequence number 1340015527; transaction id 116932
etherpad_db        | 2023-06-09 14:10:09 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
etherpad_db        | 2023-06-09 14:10:09 0 [Note] Plugin 'FEEDBACK' is disabled.
etherpad_db        | 2023-06-09 14:10:09 0 [Warning] You need to use --log-bin to make --expire-logs-days or --binlog-expire-logs-seconds work.
etherpad_db        | 2023-06-09 14:10:09 0 [Note] Server socket created on IP: '0.0.0.0'.
etherpad_db        | 2023-06-09 14:10:09 0 [Note] Server socket created on IP: '::'.
etherpad_db        | 2023-06-09 14:10:09 0 [Warning] 'proxies_priv' entry '@% root@09127af349fb' ignored in --skip-name-resolve mode.
etherpad_etherpad  | [2023-06-09 14:10:14.643] [INFO] server - Starting Etherpad...
etherpad_db        | 2023-06-09 14:10:14 4 [Warning] Access denied for user 'e-user'@'172.24.0.3' (using password: YES)
etherpad_etherpad  | [2023-06-09 14:10:14.672] [ERROR] console - ERROR: Problem while initalizing the database
etherpad_etherpad  | [2023-06-09 14:10:14.672] [ERROR] console - Error: ER_ACCESS_DENIED_ERROR: Access denied for user 'e-user'@'172.24.0.3' (using password: YES)
                                    .
                                    .
                                    .
etherpad_etherpad exited with code 1

docker ps
出力結果

CONTAINER ID   IMAGE                       COMMAND                  CREATED          STATUS                         PORTS                                                                      NAMES
555f9a3bbcec   etherpad/etherpad:latest    "docker-entrypoint.s…"   16 minutes ago   Restarting (1) 2 seconds ago                                                                              etherpad_etherpad
05cc8dbe2d51   mariadb:latest              "docker-entrypoint.s…"   16 minutes ago   Up 8 seconds                   3306/tcp                                                                   etherpad_db


docker network ls
出力結果　

[
    {
        "Name": "etherpad_default",
        "Id": "bdd1095085716f0d5940764eed5fed2b11a10120c244e49045316fc05957f160",
        "Created": "2023-06-09T13:39:00.789445888+09:00",
        "Scope": "local",
        "Driver": "bridge",
        "EnableIPv6": false,
        "IPAM": {
            "Driver": "default",
            "Options": null,
            "Config": [
                {
                    "Subnet": "172.24.0.0/16",
                    "Gateway": "172.24.0.1"
                }
            ]
        },
        "Internal": false,
        "Attachable": false,
        "Ingress": false,
        "ConfigFrom": {
            "Network": ""
        },
        "ConfigOnly": false,
        "Containers": {
            "05cc8dbe2d51887ac750aba884d8c51a98c0cd18b9fa51605d882d84c1923c2d": {
                "Name": "etherpad_db",
                "EndpointID": "45ca4806369f4000695e946dcb1f4ebcb5d37adb0fb8bf5dac127ff72b5935a5",
                "MacAddress": "XX:XX:XX:XX:XX:XX",
                "IPv4Address": "172.24.0.2/16",
                "IPv6Address": ""
            }
        },
        "Options": {},
        "Labels": {
            "com.docker.compose.network": "default",
            "com.docker.compose.project": "etherpad",
            "com.docker.compose.version": "2.17.2"
        }
    }
]

自分で試したこと

etherpad_dbコンテナで発生していたincorrect definition of table mysql.event: expected column “definer” at position 3 to have type varchar(, found type char(141))エラーを当該するテーブルのコラムをvarcharに変更することで解消　→　Problem while initalizing the databaseエラーは解消されず

docker exec -it etherpad_db bashコマンドを実行し、etherpad_dbコンテナ内から
mysql -u e-user -p コマンドで.envに記述しているパスワードを入力してmysqlサーバーにアクセスできることを確認

mysqlサーバーにアクセス後statusコマンドを実行
出力結果にportの欄がないことを確認　(今回のインシデントの原因である可能性がある?)

ホストPCで3306番ポートが開放されていることを確認

sudo ufw status
出力結果(一部)

3306                       ALLOW       172.16.0.0/12             
9001                       ALLOW       172.16.0.0/12
0

2Answer

HalHarada
@HalHarada

全く原因がわかりません。

docker compose down  etherpad_db
docker compose up -d etherpad

でしょうか？

mysql -u e-user -p

はetherpad_dbのみでなく、etherpadのコンテナ内で実行してみて下さい。

p.s.　Dockerfile,docker-compose.ymlはセットで掲載して下さい。
docker compose buildでエラーが出ていると思います。

0

Comments

  1. @takapan228

    Questioner

    回答ありがとうございます。

    まずdocker compose stop etherpad_dbですが、コンテナを立ち上げた状態で実行してもno such service: etherpad_dbと怒られ実行することができませんでした。

    また、etherpadのコンテナでmysql -u e-user -pを実行してみたかったのですが、そもそもetherpadのコンテナでエラーが起きており、正常に立ち上がってないため、docker execで中に入ることができませんでした。

    そして、imageはdocker hubからpullしたものですので、Dockerfileは存在してないです。

  2. @HalHarada

    docker compose ls
cd ......docker-compose.ymlの場所
docker compose ps
docker ps -a
docker stop etherpad_db
docker stop etherpad
docker compose down 
docker compose build
docker compose up -d etherpad

    imageはdocker hubからpullしたものなら、create databaseはimage生成の時に実施されています。
    　一方、image: mariadb:latestはcreate databaseする必要があります。
    Dockerfile以外誰が何処で実行したのでしょうか？

  3. @takapan228

    Questioner

    私が本サーバーを作成したわけではないので誰がどこで作成したかは正直わかりません。
    ただ、etherpad_db内にexecしてmysql -u root -pでmysqlサーバーにサクセスするとテーブルやデータベースは普通に存在していました。

  4. @HalHarada

    mysql -u e-user -p
    は別として、
    mysql -u root -p
    はmariraDBのデホルトデータベースです。

    mysql -h 172.24.0.2 -u e-user -p mysql

    mysql -h 172.24.0.3 -u e-user -p mysql

    で接続出来ることが、最初の一歩です。

  5. @takapan228

    Questioner

    回答ありがとうございます。

    助言の通りIPアドレスを指定してログインを行ったところ172.24.0.2は接続できたが、172.24.0.3は接続できないという結果となりました。

    docker exec -it etherpad_db bash
mysql -h 172.24.0.2 -u e-user -p

Enter password: 
Welcome to the MariaDB monitor.  Commands end with ; or \g.

MariaDB [(none)]>

    docker exec -it etherpad bash
mysql -h 172.31.0.3 -u e-user -p

Enter password: 
ERROR 2002 (HY000): Can't connect to server on '172.31.0.3' (115)

    質問文に記載しているdocker inspect etherpad_defaultの出力結果よりetehrpad_dbコンテナのIPアドレスは172.24.0.2、etherpad_etherpadコンテナは恐らく172.24.0.3であると考えています。

    また、docker netwokr 内のetherpad_default内にetherpad_etherpadコンテナが存在していないことが気がかりではあるのですが、こちらが今回のアクセス実行結果に影響しているのでしょうか?

    また、なにか別の原因があるのでしょうか?

    お手数ですが回答いただけますと幸いです。

  6. @HalHarada

    ２つのデータベースがあり、片方はcreate databaseされて、もう一方はされていないようにおもえます。そして、接続先を間違えているのでは？

    docker exec -it etherpad_db bash
mysql -h 172.24.0.2 -u e-user -p
MariaDB [(none)]>

    noneではcreate databaseの完了を確認できません
    use データベース名　まで確認してくださ。

    docker exec -it etherpad bash
mysql -h 172.31.0.3 -u e-user -p

    mysql -h 172.31.0.2 -u e-user -p
    use データベース名
    etherpadからetherpad_dbへ接続するのでは？

  7. @takapan228

    Questioner

    回答ありがとうございます。
    仰る通りにコマンドを実行したのですが、無事に接続することができました。
    ちなみに回答にある172.31.0.3は私の表記ミスです。
    正しくは172.24.0.3です。
    こちらの不手際でご迷惑をおかけして申し訳ございませんでした。

     mysql -h 172.24.0.2 -u etherpad -p 
Enter password: 
Welcome to the MariaDB monitor.  Commands end with ; or \g.

MariaDB [(none)]> use etherpad
MariaDB [etherpad]>

  8. @takapan228

    Questioner

    すみませんデータベース名ですがe-dataでした。
    なのでコマンド実行例は

     mysql -h 172.24.0.2 -u etherpad -p 
Enter password: 
Welcome to the MariaDB monitor.  Commands end with ; or \g.

MariaDB [(none)]> use e-data
MariaDB [e-data]>

    です

  9. @HalHarada

    mysql -h 172.24.0.2 -u etherpad - p e-data で一気にログインできます。

    environment:
      - VIRTUAL_HOST=etherpad
      - ADMIN_PASSWORD=${ETHERPAD_ADMIN_PASSWORD}
      - USER_PASSWORD=${ETHERPAD_USER_PASSWORD}
      - DB_TYPE=mysql
      - DB_HOST=172.24.0.2
      - DB_PORT=3306
      - DB_NAME=e-data
      - DB_USER=etherpad
      - DB_PASS=??????????
      - DB_CHARSET=utfmb4_general_ci
      - SKIN_VARIANTS=light-toolbar super-dark-background super-light-editor full-width-editor
      - REQUIRE_AUTHENTICATION=true
      - TZ=Asia/Tokyo

    値を直接記述してはどうでしょう
    DB_HOST=db の値は172.24.0.3？　又は　172.24.0.2？

    DB_CHARSET=xxxxxxxとなっていました find / -name docker-compose.ymlにて最新のファイルを探しては?

    不可解なのはetherpadが初期起動時にmariadbのrootにて、create databaseするとして、何故,172.24.0.2にe-dataが作成されておきながら、172.24.0.3に接続しにいくのか？

  10. @takapan228

    Questioner

    回答ありがとうございます。
    返信遅くなり申し訳ありません。

    本問題に関して、様々な調査を行った結果、サーバー再起動後、SQLサーバーがデータを保存しているファイル(○○.ibd)が何か余計な文字列があるというエラーのため読み込めない状態になっていることが分かり、誠に勝手ながら復旧は不可能であると判断しました。そこで、大変合理的ではない方法ではありますが、データを保存しているファイルを取得し、そのファイルを人力で解読し、新たなEtherpadコンテナ、ボリュームを作成することで一応元通りに戻すことが出来ました。

    根本的な解決にはつながっておらず、大変恐縮ですが、@HalHarada様、@shigeokamoto様に親身に回答していただいたことで、私自身様々な知見を得ることができ、並びに復旧のモチベーションを向上させることが出来ました。

    このような形になってしまい大変申し訳ございません。この度は誠にありがとうございました。

  11. @HalHarada

    復旧おめでとう!

    データベースはマルチバイト宣言してください。
    DB_CHARSET=utfmb4_general_ci

shigeokamoto
@shigeokamoto

これが原因でしょう。

 [Warning] Access denied for user 'e-user'@'172.24.0.3' (using password: YES)

mariadbに e-user が存在するかどうか
172.24.0.3からのアクセスが許容されているかどうかを確認してください。
docker network内にあると想定すると
e-user@% として許容 or 新たなユーザーを作成すれば良いと思います。

そもそも動いていて、再起動を機に動かなくなったとすると、DBインスタンスのIPアドレスが変わってしまったことが原因ではないかと思います。

0

Comments

  1. @takapan228

    Questioner

    回答ありがとうございます。
    まずmariadbにe-userが存在するかという確認ですが存在していると思います。
    コンテナ内からmariaDBサーバーにアクセスし確認しました。

    確認方法

    docker exec -it etherpad_db bash
mysql -u root -p

MariaDB [(none)]> SELECT user, host FROM mysql.user;

    出力結果

    +-------------+-----------+
| User        | Host      |
+-------------+-----------+
| e-user      | %         |
| root        | %         |
| xxxxx       | localhost |
| root        | localhost |
+-------------+-----------+
4 rows in set (0.002 sec)

    また、172.24.0.3からのアクセスが許容されているかどうかですが、e-user@%の権限の状態を見ると許容されていると考えています。

    確認方法

    MariaDB [(none)]> show grants for "e-user"@"%";

    出力結果

    +------------------------------------------------------------------------------------------------------------------+
| Grants for e-user@%                                                                                            |
+------------------------------------------------------------------------------------------------------------------+
| GRANT ALL PRIVILEGES ON *.* TO `e-user`@`%` IDENTIFIED BY PASSWORD 'xxxxxxxxx' |
| GRANT ALL PRIVILEGES ON `e-user`.* TO `e-user`@`%`                                                           |
+------------------------------------------------------------------------------------------------------------------+
2 rows in set (0.000 sec)

    しかし、@HalHarada様の助言の通りホストを172.24.0.2並びに172.24.0.3に指定してログインをすると172.24.0.2のみがログインできるという状態になっています。
    ちなみに質問文に記載しているdocker inspect etherpad_defaultなどの出力結果を見るに
    172.24.0.2 がetherpad_dbコンテナのIPアドレス
    172.24.0.3 が記載はないですが、恐らくetherpad_etherpadコンテナのIPアドレスであると考えています。

    それぞれのログイン実行結果

    mysql -h 172.24.0.2 -u e-user -p
Enter password:
welcome to the MariaDB monitor.  Commands end with ; or \g.

                            .
                            .
                            .


MariaDB [(none)]>

     mysql -h 172.24.0.3 -u e-user -p
 Enter password:
 ERROR 2002 (HY000): Can't connect to server on '172.24.0.3' (115)

    私はこれの原因としてdocker netwokr etherpad_default内に何故かetherpad_etherpadコンテナが入っていないことが1つとして挙げられると考えているのですが、あっていますでしょうか? また、その他になにか原因があるのでしょうか?

    また、サーバー再起動前までは正常に動作していました。

    そこで、DBインスタンスのIPアドレスが変わってしまった可能性が考えられるのですが、もしDBインスタンスのIPアドレスが変わってしまった場合、etherpad_etherpadコンテナはなぜ接続できなくなるのでしょうか？

  2. @shigeokamoto

    mariadbへのアクセスですが、

    mysql -h 172.24.0.2 -u e-user -p -D<データベース名(MYSQL_DATABASEで与える名前)>

    でアクセスは可能ですか？

    私はこれの原因としてdocker netwokr etherpad_default内に何故かetherpad_etherpadコンテナが入っていないことが1つとして挙げられると考えている

    これは、Restarting (1) 2 seconds ago とあるようにetherpad_etherpadコンテナが起動していない(エラーで再起動を繰り返している？)ので network ls を使って確認した際に見つからないだけだと思います。172.24.0.3がアクセス元なのでこれがetherpadコンテナでしょう。

    compose up の標準出力にもdb,etherpadのログが混載して表示されますが、別のターミナルから以下のコマンドを実行すれば etherpadコンテナのログを確認できます。
    ログにはもう少し見るべきところがあるかもしれません。

    docker logs -f etherpad_etherpad

    ところで、

    etherpad_db | 2023-06-09 14:10:14 4 [Warning] Access denied for user 'e-user'@'172.24.0.3' (using password: YES)

    dbインスタンスはe-userでのアクセスをはじいているのですが、

    etherpad_etherpad | [2023-06-09 14:10:14.672] [ERROR] console - Error: ER_ACCESS_DENIED_ERROR: Access denied for user 'eno-1'@'172.24.0.3' (using password: YES)

    etherpad側のログでは eno-1 というユーザーでアクセスを試みて拒否されています。
    ログの形式から mariadb(=dbコンテナ)から返されたエラーだと思いますが、eno-1というユーザーに心当たりはありますか？

  3. @takapan228

    Questioner

    回答ありがとうございます。

    指定されたコマンドでのSQLサーバーへのアクセスですが可能でした。

    実行結果

    docker exec -it etherpad_db bash
mysql -h 172.24.0.2 -u e-user -p -D e-data
Enter password: 
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A
                         . 
                         .
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 [e-data]>

    また、一応172.24.0.3でもログインしてみましたが、うまくいきませんでした。

    実行結果

    docker exec -it etherpad_db bash
mysql -h 172.24.0.3 -u e-user -p -D e-data
ERROR 2002 (HY000): Can't connect to server on '172.24.0.3' (115)

    etherpad_etherpadコンテナのログを見ると以下のようになっていました。

    docker logs -f etherpad_etherpad

[2023-06-10 12:54:32.570] [DEBUG] console - Running on Node v14.18.1 (minimum required Node version: 10.17.0)
[2023-06-10 12:54:32.579] [INFO] console - All relative paths will be interpreted relative to the identified Etherpad base dir: /opt/etherpad-lite
[2023-06-10 12:54:32.580] [DEBUG] AbsolutePaths - Relative path "settings.json" can be rewritten to "/opt/etherpad-lite/settings.json"
[2023-06-10 12:54:32.580] [DEBUG] AbsolutePaths - Relative path "credentials.json" can be rewritten to "/opt/etherpad-lite/credentials.json"
[2023-06-10 12:54:32.592] [INFO] console - settings loaded from: /opt/etherpad-lite/settings.json
[2023-06-10 12:54:32.592] [DEBUG] console - Environment variable "TITLE" not found for configuration key "title". Falling back to default value.
[2023-06-10 12:54:32.592] [DEBUG] console - Environment variable "FAVICON" not found for configuration key "favicon". Falling back to default value.
[2023-06-10 12:54:32.593] [DEBUG] console - Environment variable "SKIN_NAME" not found for configuration key "skinName". Falling back to default value.
[2023-06-10 12:54:32.593] [DEBUG] console - Configuration key "skinVariants" will be read from environment variable "SKIN_VARIANTS"
[2023-06-10 12:54:32.593] [DEBUG] console - Environment variable "IP" not found for configuration key "ip". Falling back to default value.
[2023-06-10 12:54:32.593] [DEBUG] console - Environment variable "PORT" not found for configuration key "port". Falling back to default value.
[2023-06-10 12:54:32.594] [DEBUG] console - Environment variable "SHOW_SETTINGS_IN_ADMIN_PAGE" not found for configuration key "showSettingsInAdminPage". Falling back to default value.
[2023-06-10 12:54:32.594] [DEBUG] console - Configuration key "dbType" will be read from environment variable "DB_TYPE"
[2023-06-10 12:54:32.594] [DEBUG] console - Configuration key "host" will be read from environment variable "DB_HOST"
[2023-06-10 12:54:32.594] [DEBUG] console - Configuration key "port" will be read from environment variable "DB_PORT"
[2023-06-10 12:54:32.594] [DEBUG] console - Configuration key "database" will be read from environment variable "DB_NAME"
[2023-06-10 12:54:32.595] [DEBUG] console - Configuration key "user" will be read from environment variable "DB_USER"
[2023-06-10 12:54:32.595] [DEBUG] console - Configuration key "password" will be read from environment variable "DB_PASS"
[2023-06-10 12:54:32.595] [DEBUG] console - Configuration key "charset" will be read from environment variable "DB_CHARSET"
[2023-06-10 12:54:32.595] [DEBUG] console - Environment variable "DB_FILENAME" not found for configuration key "filename". Falling back to default value.
[2023-06-10 12:54:32.595] [DEBUG] console - Environment variable "DEFAULT_PAD_TEXT" not found for configuration key "defaultPadText". Falling back to default value.
[2023-06-10 12:54:32.596] [DEBUG] console - Environment variable "PAD_OPTIONS_NO_COLORS" not found for configuration key "noColors". Falling back to default value.
[2023-06-10 12:54:32.596] [DEBUG] console - Environment variable "PAD_OPTIONS_SHOW_CONTROLS" not found for configuration key "showControls". Falling back to default value.
[2023-06-10 12:54:32.596] [DEBUG] console - Environment variable "PAD_OPTIONS_SHOW_CHAT" not found for configuration key "showChat". Falling back to default value.
[2023-06-10 12:54:32.596] [DEBUG] console - Environment variable "PAD_OPTIONS_SHOW_LINE_NUMBERS" not found for configuration key "showLineNumbers". Falling back to default value.
[2023-06-10 12:54:32.597] [DEBUG] console - Environment variable "PAD_OPTIONS_USE_MONOSPACE_FONT" not found for configuration key "useMonospaceFont". Falling back to default value.
[2023-06-10 12:54:32.597] [DEBUG] console - Environment variable "PAD_OPTIONS_USER_NAME" not found for configuration key "userName". Falling back to default value.
[2023-06-10 12:54:32.597] [DEBUG] console - Environment variable "PAD_OPTIONS_USER_COLOR" not found for configuration key "userColor". Falling back to default value.
[2023-06-10 12:54:32.597] [DEBUG] console - Environment variable "PAD_OPTIONS_RTL" not found for configuration key "rtl". Falling back to default value.
[2023-06-10 12:54:32.597] [DEBUG] console - Environment variable "PAD_OPTIONS_ALWAYS_SHOW_CHAT" not found for configuration key "alwaysShowChat". Falling back to default value.
[2023-06-10 12:54:32.597] [DEBUG] console - Environment variable "PAD_OPTIONS_CHAT_AND_USERS" not found for configuration key "chatAndUsers". Falling back to default value.
[2023-06-10 12:54:32.598] [DEBUG] console - Environment variable "PAD_OPTIONS_LANG" not found for configuration key "lang". Falling back to default value.
[2023-06-10 12:54:32.598] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_ALT_F9" not found for configuration key "altF9". Falling back to default value.
[2023-06-10 12:54:32.598] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_ALT_C" not found for configuration key "altC". Falling back to default value.
[2023-06-10 12:54:32.598] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_CMD_SHIFT_2" not found for configuration key "cmdShift2". Falling back to default value.
[2023-06-10 12:54:32.598] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_DELETE" not found for configuration key "delete". Falling back to default value.
[2023-06-10 12:54:32.598] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_RETURN" not found for configuration key "return". Falling back to default value.
[2023-06-10 12:54:32.599] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_ESC" not found for configuration key "esc". Falling back to default value.
[2023-06-10 12:54:32.599] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_CMD_S" not found for configuration key "cmdS". Falling back to default value.
[2023-06-10 12:54:32.599] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_TAB" not found for configuration key "tab". Falling back to default value.
[2023-06-10 12:54:32.599] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_CMD_Z" not found for configuration key "cmdZ". Falling back to default value.
[2023-06-10 12:54:32.599] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_CMD_Y" not found for configuration key "cmdY". Falling back to default value.
[2023-06-10 12:54:32.599] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_CMD_I" not found for configuration key "cmdI". Falling back to default value.
[2023-06-10 12:54:32.600] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_CMD_B" not found for configuration key "cmdB". Falling back to default value.
[2023-06-10 12:54:32.600] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_CMD_U" not found for configuration key "cmdU". Falling back to default value.
[2023-06-10 12:54:32.600] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_CMD_5" not found for configuration key "cmd5". Falling back to default value.
[2023-06-10 12:54:32.600] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_CMD_SHIFT_L" not found for configuration key "cmdShiftL". Falling back to default value.
[2023-06-10 12:54:32.600] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_CMD_SHIFT_N" not found for configuration key "cmdShiftN". Falling back to default value.
[2023-06-10 12:54:32.600] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_CMD_SHIFT_1" not found for configuration key "cmdShift1". Falling back to default value.
[2023-06-10 12:54:32.600] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_CMD_SHIFT_C" not found for configuration key "cmdShiftC". Falling back to default value.
[2023-06-10 12:54:32.601] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_CMD_H" not found for configuration key "cmdH". Falling back to default value.
[2023-06-10 12:54:32.601] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_CTRL_HOME" not found for configuration key "ctrlHome". Falling back to default value.
[2023-06-10 12:54:32.601] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_PAGE_UP" not found for configuration key "pageUp". Falling back to default value.
[2023-06-10 12:54:32.601] [DEBUG] console - Environment variable "PAD_SHORTCUTS_ENABLED_PAGE_DOWN" not found for configuration key "pageDown". Falling back to default value.
[2023-06-10 12:54:32.601] [DEBUG] console - Environment variable "SUPPRESS_ERRORS_IN_PAD_TEXT" not found for configuration key "suppressErrorsInPadText". Falling back to default value.
[2023-06-10 12:54:32.601] [DEBUG] console - Environment variable "REQUIRE_SESSION" not found for configuration key "requireSession". Falling back to default value.
[2023-06-10 12:54:32.602] [DEBUG] console - Environment variable "EDIT_ONLY" not found for configuration key "editOnly". Falling back to default value.
[2023-06-10 12:54:32.602] [DEBUG] console - Environment variable "MINIFY" not found for configuration key "minify". Falling back to default value.
[2023-06-10 12:54:32.602] [DEBUG] console - Environment variable "MAX_AGE" not found for configuration key "maxAge". Falling back to default value.
[2023-06-10 12:54:32.602] [WARN] console - Environment variable "ABIWORD" does not contain any value for configuration key "abiword", and no default was given. Returning null.
[2023-06-10 12:54:32.602] [WARN] console - Environment variable "SOFFICE" does not contain any value for configuration key "soffice", and no default was given. Returning null.
[2023-06-10 12:54:32.603] [WARN] console - Environment variable "TIDY_HTML" does not contain any value for configuration key "tidyHtml", and no default was given. Returning null.
[2023-06-10 12:54:32.603] [DEBUG] console - Environment variable "ALLOW_UNKNOWN_FILE_ENDS" not found for configuration key "allowUnknownFileEnds". Falling back to default value.
[2023-06-10 12:54:32.603] [DEBUG] console - Configuration key "requireAuthentication" will be read from environment variable "REQUIRE_AUTHENTICATION"
[2023-06-10 12:54:32.603] [DEBUG] console - Environment variable "REQUIRE_AUTHORIZATION" not found for configuration key "requireAuthorization". Falling back to default value.
[2023-06-10 12:54:32.603] [DEBUG] console - Environment variable "TRUST_PROXY" not found for configuration key "trustProxy". Falling back to default value.
[2023-06-10 12:54:32.603] [DEBUG] console - Environment variable "COOKIE_SAME_SITE" not found for configuration key "sameSite". Falling back to default value.
[2023-06-10 12:54:32.604] [DEBUG] console - Environment variable "DISABLE_IP_LOGGING" not found for configuration key "disableIPlogging". Falling back to default value.
[2023-06-10 12:54:32.604] [DEBUG] console - Environment variable "AUTOMATIC_RECONNECTION_TIMEOUT" not found for configuration key "automaticReconnectionTimeout". Falling back to default value.
[2023-06-10 12:54:32.604] [DEBUG] console - Environment variable "FOCUS_LINE_PERCENTAGE_ABOVE" not found for configuration key "editionAboveViewport". Falling back to default value.
[2023-06-10 12:54:32.604] [DEBUG] console - Environment variable "FOCUS_LINE_PERCENTAGE_BELOW" not found for configuration key "editionBelowViewport". Falling back to default value.
[2023-06-10 12:54:32.604] [DEBUG] console - Environment variable "FOCUS_LINE_DURATION" not found for configuration key "duration". Falling back to default value.
[2023-06-10 12:54:32.605] [DEBUG] console - Environment variable "FOCUS_LINE_CARET_SCROLL" not found for configuration key "scrollWhenCaretIsInTheLastLineOfViewport". Falling back to default value.
[2023-06-10 12:54:32.605] [DEBUG] console - Environment variable "FOCUS_LINE_PERCENTAGE_ARROW_UP" not found for configuration key "percentageToScrollWhenUserPressesArrowUp". Falling back to default value.
[2023-06-10 12:54:32.605] [DEBUG] console - Configuration key "password" will be read from environment variable "ADMIN_PASSWORD"
[2023-06-10 12:54:32.605] [DEBUG] console - Configuration key "password" will be read from environment variable "USER_PASSWORD"
[2023-06-10 12:54:32.605] [DEBUG] console - Environment variable "LOAD_TEST" not found for configuration key "loadTest". Falling back to default value.
[2023-06-10 12:54:32.605] [DEBUG] console - Environment variable "IMPORT_EXPORT_RATE_LIMIT_WINDOW" not found for configuration key "windowMs". Falling back to default value.
[2023-06-10 12:54:32.606] [DEBUG] console - Environment variable "IMPORT_EXPORT_MAX_REQ_PER_IP" not found for configuration key "max". Falling back to default value.
[2023-06-10 12:54:32.606] [DEBUG] console - Environment variable "IMPORT_MAX_FILE_SIZE" not found for configuration key "importMaxFileSize". Falling back to default value.
[2023-06-10 12:54:32.606] [DEBUG] console - Environment variable "COMMIT_RATE_LIMIT_DURATION" not found for configuration key "duration". Falling back to default value.
[2023-06-10 12:54:32.606] [DEBUG] console - Environment variable "COMMIT_RATE_LIMIT_POINTS" not found for configuration key "points". Falling back to default value.
[2023-06-10 12:54:32.606] [DEBUG] console - Environment variable "EXPOSE_VERSION" not found for configuration key "exposeVersion". Falling back to default value.
[2023-06-10 12:54:32.606] [DEBUG] console - Environment variable "LOGLEVEL" not found for configuration key "loglevel". Falling back to default value.
[2023-06-10 12:54:32.607] [INFO] console - No credentials file found in /opt/etherpad-lite/credentials.json. Ignoring.
[2023-06-10 12:54:32.608] [INFO] console - Using skin "colibris" in dir: /opt/etherpad-lite/src/static/skins/colibris
[2023-06-10 12:54:32.608] [INFO] console - Session key loaded from: /opt/etherpad-lite/SESSIONKEY.txt
[2023-06-10 12:54:32.608] [INFO] console - Random string used for versioning assets: d61c5e0e

[2023-06-10 12:54:32.761] [INFO] server - Starting Etherpad...
[2023-06-10 12:54:32.790] [ERROR] console - ERROR: Problem while initalizing the database
[2023-06-10 12:54:32.790] [ERROR] console - Error: ER_ACCESS_DENIED_ERROR: Access denied for user 'e-user'@'172.24.0.3'(using password: YES)

    at Handshake.Sequence._packetToError (/opt/etherpad-lite/src/node_modules/mysql/lib/protocol/sequences/Sequence.js:47:14)
    at Handshake.ErrorPacket (/opt/etherpad-lite/src/node_modules/mysql/lib/protocol/sequences/Handshake.js:123:18)
    at Protocol._parsePacket (/opt/etherpad-lite/src/node_modules/mysql/lib/protocol/Protocol.js:291:23)
    at Parser._parsePacket (/opt/etherpad-lite/src/node_modules/mysql/lib/protocol/Parser.js:433:10)
    at Parser.write (/opt/etherpad-lite/src/node_modules/mysql/lib/protocol/Parser.js:43:10)
    at Protocol.write (/opt/etherpad-lite/src/node_modules/mysql/lib/protocol/Protocol.js:38:16)
    at Socket.<anonymous> (/opt/etherpad-lite/src/node_modules/mysql/lib/Connection.js:88:28)
    at Socket.<anonymous> (/opt/etherpad-lite/src/node_modules/mysql/lib/Connection.js:526:10)
    at Socket.emit (events.js:400:28)
    at addChunk (internal/streams/readable.js:293:12)
    --------------------
    at Protocol._enqueue (/opt/etherpad-lite/src/node_modules/mysql/lib/protocol/Protocol.js:144:48)
    at Protocol.handshake (/opt/etherpad-lite/src/node_modules/mysql/lib/protocol/Protocol.js:51:23)
    at Connection.connect (/opt/etherpad-lite/src/node_modules/mysql/lib/Connection.js:116:18)
    at Connection._implyConnect (/opt/etherpad-lite/src/node_modules/mysql/lib/Connection.js:454:10)
    at Connection.query (/opt/etherpad-lite/src/node_modules/mysql/lib/Connection.js:196:8)
    at /opt/etherpad-lite/src/node_modules/ueberdb2/databases/mysql_db.js:48:22
    at new Promise (<anonymous>)
    at exports.Database._query (/opt/etherpad-lite/src/node_modules/ueberdb2/databases/mysql_db.js:47:16)
    at exports.Database.init (/opt/etherpad-lite/src/node_modules/ueberdb2/databases/mysql_db.js:80:14)
    at exports.Database.init (/opt/etherpad-lite/src/node_modules/ueberdb2/lib/CacheAndBufferLayer.js:264:24)

    このログでは様々な環境変数がnot foundと怒られていますが、例 "PAD_OPTIONS_USER_NAME" not found for configuration key "userName". これらの環境変数を設定しているようなファイルは見当たりませんでした。

    また、etherpad_etherpad コンテナの etherpad_etherpad | [2023-06-09 14:10:14.672] [ERROR] console - Error: ER_ACCESS_DENIED_ERROR: Access denied for user 'eno-1'@'172.24.0.3' (using password: YES) に関しては私の表記ミスです。

    実はユーザー名をe-userに変換して実行結果などを出力していたのですが、その変換を誤ってeno-1にしてしまいました。こちらの不手際で余計なお時間を取らせてしまい大変申し訳ございません。

    なので実際のエラー文は
    etherpad_etherpad | [2023-06-09 14:10:14.672] [ERROR] console - Error: ER_ACCESS_DENIED_ERROR: Access denied for user 'e-user'@'172.24.0.3' (using password: YES)
    です

    また、実はcompose stopやcompose dowmなどを行っていると、etehrpad関係のdocker network bridgeやコンテナのIPアドレスが172.〇〇.0.〇〇から192.168.〇〇.〇〇に変わってしまったのですが、これは正常な動作でしょうか?

    ちなみにこれまでの質問の回答に対するコメントで172.24.0.2や172.24.0.3といったIPアドレスが登場しているのですが、実際はこれまで何度もdocker compose downなどを経てIPアドレスが変わっています。なので別のIPアドレスで実行しており、出力結果もそれに準じた別のIPアドレスが出力されています。それを今までの質問の回答では、すべて172.24.0.○に書き換えておりました。

    例
    実際の実行結果

    mysql -h 172.31.0.2 -u e-user -p -D e-data

    回答のコメントに記載した実行結果

    mysql -h 172.24.0.2 -u e-user -p -D e-data

  4. @shigeokamoto

    ローカルからのmysqlコマンドだとアクセスできてしまうのですね。

    Error: ER_ACCESS_DENIED_ERROR: Access denied for user 'e-user'@'172.24.0.3'(using password: YES)

    とはいえ、ehterpadコンテナからのアクアセスは失敗しているので何かおかしいはずです。

    etherpadコンテナは起動できないのでテスト用コンテナを起動して確認してみましょうか。

    compose.yaml をバックアップしたうえで以下を追記してください。/var/lib/mysqlにボリュームはマウントせず、あとは今の設定なので起動できると思います。

      test:
    image: mariadb:latest
    container_name: etherpad_test
    environment:
      - MYSQL_ROOT_PASSWORD=${MYSQL_ROOT_PASSWORD}
      - MYSQL_DATABASE=${MYSQL_DATABASE}
      - MYSQL_USER=${MYSQL_USER}
      - MYSQL_PASSWORD=${MYSQL_PASSWORD}
      - TZ=Asia/Tokyo
      - DB_HOST=db
      - DB_PORT=3306
      - DB_NAME=${MYSQL_DATABASE}
      - DB_USER=${MYSQL_USER}
      - DB_PASS=${MYSQL_PASSWORD}

    このコンテナからdbインスタンスへのアクセスは可能でしょうか？

    docker exec -it etherpad_test sh
mysql -h $DB_HOST -u $DB_USER -p"$DB_PASS" -D $DB_NAME

    compose stopやcompose dowmなどを行っていると、etehrpad関係のdocker network bridgeやコンテナのIPアドレスが172.〇〇.0.〇〇から192.168.〇〇.〇〇に変わってしまった

    docker network は予めリザーブされたアドレスブロックから適当に割り当てられるのでアドレスの割り当てが変わることは問題ありません。

  5. @takapan228

    Questioner

    回答ありがとうございます。
    返信遅くなり申し訳ありません。

    本問題に関して、様々な調査を行った結果、サーバー再起動後、SQLサーバーがデータを保存しているファイル(○○.ibd)が何か余計な文字列があるというエラーのため読み込めない状態になっていることが分かり、誠に勝手ながら復旧は不可能であると判断しました。そこで、大変合理的ではない方法ではありますが、データを保存しているファイルを取得し、そのファイルを人力で解読し、新たなEtherpadコンテナ、ボリュームを作成することで一応元通りに戻すことが出来ました。

    根本的な解決にはつながっておらず、大変恐縮ですが、@shigeokamoto様、@HalHarada様に親身に回答していただいたことで、私自身様々な知見を得ることができ、並びに復旧のモチベーションを向上させることが出来ました。

    このような形になってしまい大変申し訳ございません。この度は誠にありがとうございました。

Your answer might help someone💌

LoginSign Up

Popular Questions