Docker for Mac で executeクエリが動きません。。。

Question

• 環境

Docker for Mac (18.03.1-ce)
phalcon(3.3.2)

最近、XAMPPからDockerに切り替えました。
Docker for Macで環境構築をして、アプリケーションを動かしたいのですが、なぜか502エラーが出ました。

そこで、xdebugを使ってデバッグしたところ、indexControllerに記載されていた、executeクエリが失敗していました。（データベースとの接続の問題？）

しかし、他の開発者2人（LinuxとMac）はうまくいっています。
他の2人はうまくいっているので、コードに問題はないかと思うのですが、データベース接続も含めてphalconやdocker、apcなどのバージョンは全て同じであることは確認しました。
executeクエリが失敗している原因で考えられるものは他にありますでしょうか？

ご回答よろしくお願いします。。

追記

• 実際にエラーが発生しているソース

$WritingTotalPointsは、ブログの一ヶ月間の文字数の合計です。
$columnsと$startOfMonth, $startOfNextMonthはXdebugを使って変数にちゃんとデータが入っていることを確認しました。
dockerのコンテナに入り、blogテーブルとそれぞれのデータがあることは確認しました。
execute(); で失敗しています。

$WritingTotalPoints = \Blog::query()
            ->columns($columns)
            ->innerJoin('Site', 'Site.id = Blog.siteId')
            ->where("Blog.contentDueDate >= '{$startOfMonth}' AND Blog.contentDueDate < '{$startOfNextMonth}'")
            ->execute();

• DB接続情報

セキュリティ的にはよくないかもしれませんが、そこはスルーで、、、。

'database' => [
        'isAutoCast' => true,
        'mysql' => [
            'development' => [
                'adapter' => 'Mysql',
                'host' => getenv('DB_HOST') ?: 'localhost',
                'username' => 'root',
                'password' => '',
                'dbname' => 'test',
                'persistent' => true
            ],
            'production' => [
                'adapter' => 'Mysql',
                'host' => getenv('DB_HOST'),
                'username' => getenv('DB_USER'),
                'password' => getenv('DB_PASS'),
                'dbname' => getenv('DB_NAME'),
                'persistent' => true
            ]
        ],
        'results' => [
            'flatten' => true,
            'masterValues' => 'extract', // null | extract
            'scope' => 'public', // null | public | protected | private
        ]
    ],

ログの追記

PHPのエラーログ

phalcon_php | 172.18.0.4 -  20/Jun/2018:03:34:43 +0000 "GET /index.php" 200
phalcon_php | [20-Jun-2018 03:34:44] WARNING: [pool www] child 8 exited on signal 4 (SIGILL) after 6.481382 seconds from start
phalcon_php | [20-Jun-2018 03:34:44] NOTICE: [pool www] child 9 started

nginxのエラーログ

phalcon_nginx | 172.18.0.1 - - [20/Jun/2018:03:36:35 +0000] "GET / HTTP/1.1" 200 394 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_
5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.87 Safari/537.36" "-"
phalcon_nginx | 172.18.0.1 - - [20/Jun/2018:03:36:36 +0000] "GET /favicon.ico HTTP/1.1" 200 1150 "http://test.local/" "Mozilla/5.0 (
Macintosh; Intel Mac OS X 10_13_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.87 Safari/537.36" "-"
phalcon_nginx | 172.18.0.1 - - [20/Jun/2018:03:36:36 +0000] "GET /api/initialize?timezone=Asia/Tokyo HTTP/1.1" 502 568 "http://test.
local/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.87 Safari/537.36" "-"
phalcon_nginx | 2018/06/20 03:36:36 [error] 13#13: *26 recv() failed (104: Connection reset by peer) while reading response header from upstream, client: 172.18.0.1, server: test.local, request: "GET /api/initialize?timezone=Asia/Tokyo HTTP/1.1", upstream: "fastcgi://172.18.0.3:9000", host: "test.local", referrer: "http://test.local/"

mysqlのエラーログ

今実行してもmysqlのエラーは何も出ないのですが、知らないうちにエラーが溜まっていました。

phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Note] InnoDB: Compressed tables use zlib 1.2.8                           [0/139]
phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Note] InnoDB: Using Linux native AIO                                           
phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Note] InnoDB: Number of pools: 1                                               
phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Note] InnoDB: Using SSE2 crc32 instructions                                    
phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Note] InnoDB: Initializing buffer pool, total size = 256M, instances = 1, chunk
size = 128M
phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Note] InnoDB: Completed initialization of buffer pool                          
phalcon_mariadb | 2018-06-20  3:30:36 140097225074432 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread pr
iority can be changed. See the man page of setpriority().
phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Note] InnoDB: Highest supported file format is Barracuda.
phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Note] InnoDB: 128 out of 128 rollback segments are active.
phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Note] InnoDB: Creating shared tablespace for temporary tables
phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file
 full; Please wait ...
phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Note] InnoDB: Waiting for purge to start
phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Note] InnoDB: 5.7.22 started; log sequence number 172722127
phalcon_mariadb | 2018-06-20  3:30:36 140096783243008 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Note] Plugin 'FEEDBACK' is disabled.
phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Note] Server socket created on IP: '::'.
phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Warning] 'proxies_priv' entry '@% root@273f5a19507c' ignored in --skip-name-reso
lve mode.
phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Note] Reading of all Master_info entries succeded
phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Note] Added new Master_info '' to hash table
phalcon_mariadb | 2018-06-20  3:30:36 140097962047360 [Note] mysqld: ready for connections.
phalcon_mariadb | Version: '10.2.15-MariaDB-10.2.15+maria~jessie'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binar
y distribution
phalcon_mariadb | 2018-06-20  3:30:38 140096783243008 [Note] InnoDB: Buffer pool(s) load completed at 180620  3:30:38

追記 Docer-compose.yml

version: '3.4'

services:
  mysql:
    restart: always
    image: mariadb:10.2
    container_name: phalcon_mariadb
    ports:
      - 3306:3306
    environment:
      MYSQL_DATABASE: test
      MYSQL_ALLOW_EMPTY_PASSWORD: 'yes'
    volumes:
      - mysql:/var/lib/mysql

  php:
    restart: always
    build: ./
    container_name: phalcon_php
    ports:
      # php-fpm
      - 9000:9000
    environment:
      APP_ENV: 'development'
      XDEBUG_REMOTE_HOST: 'host.docker.internal'
      XDEBUG_REMOTE_PORT: '9005'
      XDEBUG_IDE: 'VSCODE'
      DB_HOST: 'mysql'
    volumes:
      - ./php:/app/php
      - ./html:/app/html
      - ./config/www.conf:/usr/local/etc/php-fpm.d/www.conf
      - ./config/phalcon.ini:/usr/local/etc/php/conf.d/phalcon.ini
    depends_on:
      - mysql

  nginx:
    restart: always
    image: phalconphp/nginx:1.10
    container_name: phalcon_nginx
    ports:
      - 80:80
    volumes:
      - ./config/nginx.conf:/etc/nginx/conf.d/test.template
      - ./src:/app/src
      - ./html:/app/html
    environment:
      HOST_NAME: 'test.local'
      PHP_CONTAINER: 'php'
    command: >
      sh -c "envsubst \"`env | awk -F = '{printf \" $$%s\", $$1}'`\"
      < /etc/nginx/conf.d/test.template
      > /etc/nginx/conf.d/default.conf
      && nginx -g 'daemon off;'"
    depends_on:
      - php

# docker volume create --name=mysql
volumes:
  mysql:
    external: true

Comments

[takyafumin]

実際にエラーが発生しているソース、phpでのエラー、DB接続情報、DBの稼働状況を質問に追記していただけますか？

[n_oshiumi]

ありがとうございます。エラーが発生しているソースとDB接続情報を追記しました。DBの稼働状況とは何をお伝えすればよろしいでしょうか？

Answer 1

「ソースコードが同じ」であるが、動く環境と動かない環境があるということですので、環境面に問題があるかと思います。
環境面とは、ここでは「データベース」が一番怪しいです。

• DBが起動していない
• DBの認証情報が違う(APP側)
• DBの認証情報が違つ(DB側) -> mysqlの認証情報

「DBの稼働状況」については、「実際にDBが起動しているか」という点を確認させて頂きたいという内容でした。
実際にDB接続してデータ確認していますので、DBは稼働しているようですね。

提示頂いた「DB接続情報」を見る限り、複数環境分定義されています。
現在構築した環境では「development」「production」のどちらを利用していますか。
どちらも環境変数を利用していますので、他の端末と環境変数の違いを比べて見ると良いと思います。

「development」であれば、DB_HOSTが適切に設定されていないとlocalhostに接続しようしますが、APPサーバから見て、DBサーバはlocalhostで正しいですか？

「production」であれば、DB接続情報は環境変数からそれぞれ取得するようになっているようですが、正しく環境変数に設定されていますか？

上記も正しく設定されているとすると、mysqlの認証情報（ユーザ情報と権限）に違いがありそうですね。
まずは上記環境変数に違いがないか切り分けをお願いします。

コメントを受けての追記

DB稼働状態やDB接続設定については問題なさそうですね。
前提としての確認ですが、phpのmysqlドライバはインストールされていますか？
phalconのRequirementsを満たしていれば問題ありません。
最新バージョンですとこちらのページですね。
https://docs.phalconphp.com/ja/3.3/installation

あと、実際に発生しているPHPのエラーメッセージを追記してもらえますか？
そこから情報が得られるかもしれません。

コメントを受けての追記２

それであれば、phpのエラーを確認することを優先しましょう。
xdebugを使っている様であれば、xdebugの機能で確認できるかと思います。
(visual studio codeでの確認イメージ)

別件ですが、お使いのphalconのバージョンも質問に追記ください。

コメントを受けての追記３

例えば以下の様にエラー発生箇所にtry~catchを仕込んでエラーを確認してみてください。
DB接続の問題か、sqlの問題か、何の問題か切り分けが必要です。

try {
  $WritingTotalPoints = \Blog::query()
              ->columns($columns)
              ->innerJoin('Site', 'Site.id = Blog.siteId')
              ->where("Blog.contentDueDate >= '{$startOfMonth}' AND Blog.contentDueDate < '{$startOfNextMonth}'")
              ->execute();
} catch (\Exception $e) {
    echo $e->getMessage() . '<br>';
    echo '<pre>' . $e->getTraceAsString() . '</pre>';
    exit;
}

Comments

[n_oshiumi]

確認したところ、`development `を使用していました。

getenv('DB_HOST')で正しかったです。

それでも、うまくいきませんでした。。。

`SELECT user,host FROM mysql.user;`で、ユーザーを確認したところ
ユーザーは「root」 ホストは「%」
ユーザーは「root」ホストは「localhost」
2 rows in set (0.01 sec)

でした。

権限は
```
show grants for 'root'@'%';
GRANT ALL PRIVILEGES ON *.* TO 'root'@'%' WITH GRANT OPTION
```

```
show grants for 'root'@'localhost'GRANT ALL PRIVILEGES ON *.* TO 'root'@'localhost' WITH GRANT OPTION
GRANT PROXY ON ''@'%' TO 'root'@'localhost' WITH GRANT OPTION
```

と表示されました。

mysqlの認証情報も大丈夫そうです。
まだ他に原因が見つかっていません、、、。

[takyafumin]

確認ありがとうございます。
セキュリティ上、rootのパスワードは空値以外となる場合が多いと思いますが、rootのパスワードは空値が正しいでしょうか。dockerコンテナ上のmysqlコマンドではパスワードなしでデータベース接続が出来ていますか？

[n_oshiumi]

回答ありがとうございます。
パスワードは空値であることを確認しました。
mysql -h127.0.0.1 -uroot データベース名　で接続できます！

[n_oshiumi]

ありがとうございます。
質問にエラーログを追記しました。
phalconのrequirementをこれから確認してみます。

[n_oshiumi]

phalconのrequirementは満たしていました！

[takyafumin]

mysqlのドライバはインストールされている様ですね。エラーについてはエラーログではなく、発生しているphpのエラー（Exception）を記載してください。

[n_oshiumi]

エラーは「502 Bad Gateway nginx」しか出ていません・・・。

[n_oshiumi]

ありがとうございます。
今原因不明でVScodeのPHPdebugでブレークポイントをおいても止まらなくなったのですが、
以前行った時は、何もエラーが出ずにそこから進まなくなるだけでした。
それは何回やっても同様でした。

[n_oshiumi]

コメントを受けての追記３に関して、
実行してみたところ、全く何も変わらずに502エラーが出ていました。。。

[takyafumin]

今の状態でリクエストの一番初めからxdebugにてどこまで処理が実行できるか確認することは出来ますか？

[n_oshiumi]

前と変わりませんでした。

```
class Model extends \Phalcon\Mvc\Model
```

このラインに来たときに、`Unknown thread ID 2`というエラーが出ます。
これはxdebugのバグですか？

このファイルはベースとなるモデルのファイルです。

[takyafumin]

> 前と変わりませんでした。
エラーは「execute()」で発生していると思っていましたが、今は状況が違うのでしょうか？
エラーが発生しているソースを質問へ追記してください。可能であれば、そのclassを利用している箇所でtry〜catchを設定してExceptionを確認してください。

[takyafumin]

こちらでは現象再現できないため、質問文にDockerfile（またはdocker-compose.yml）を記載できますか？同じコンテナでこちらで動作しているソースで同現象が再現できれば更なる調査ができるかと思います。

[n_oshiumi]

失礼しました。
下のコードを徐々にステップインすると、「class Model extends \Phalcon\Mvc\Model」のラインで止まってしまい、モデルまできているということは、executeの失敗だと考えて質問させていただいていました。
もう少し詳細に説明すべきでした、申し訳ありません。

$WritingTotalPoints = \Blog::query()
->columns($columns)
->innerJoin('Site', 'Site.id = Blog.siteId')
->where("Blog.contentDueDate >= '{$startOfMonth}' AND Blog.contentDueDate < '{$startOfNextMonth}'")
->execute();

[takyafumin]

ソースではBlogモデルを使用しているように見えますが、Modelモデルを使用しているのでしょうか？Blogモデルのソースを質問文に追記出来ますか？

Answer 2

macではできなかったけど、windowsでやったらできました。