SQL文をデバッグログに出力する方法

本記事は、CakePHPでSQL文をデバッグログに出力する方法を解説しています。
SQL文を確認する方法は、個別の画面に変数をダンプしたりするなど、色々とあると思います。

今回は、環境設定を変更することで、アプリケーションのすべてで実行するSQL文を、デバッグログに出力する方法です。

app.phpファイルの編集
デバッグログの場所
ログの内容

app.phpファイルの編集

下記の場所にある app.php ファイルの設定変更をすることで、SQLログが出力されるようになります。

ファイルの場所

/home/hogehoge/example.com/public_html/sandbox/app/config
|--Migrations
|  |--20190123030101_Initial.php
|  |--schema-dump-default.lock
|--Seeds
|--app.default.php
|--app.php　※対象ファイル
|--bootstrap.php
|--bootstrap_cli.php
|--paths.php
|--routes.php
|--schema
|  |--i18n.sql
|  |--sessions.sql


app.php

    /**
     * Connection information used by the ORM to connect
     * to your application's datastores.
     * Drivers include Mysql Postgres Sqlite Sqlserver
     * See vendor\cakephp\cakephp\src\Database\Driver for complete list
     */
    'Datasources' =&gt; [
        'default' =&gt; [
            'className' =&gt; 'Cake\Database\Connection',
            'driver' =&gt; 'Cake\Database\Driver\Mysql',
            'persistent' =&gt; false,
            'host' =&gt; 'mysqlxxxx.xserver.jp',
            /**
             * CakePHP will use the default DB port based on the driver selected
             * MySQL on MAMP uses port 8889, MAMP users will want to uncomment
             * the following line and set the port accordingly
             */
            //'port' =&gt; 'nonstandard_port_number',
            'username' =&gt; 'hogehoge',
            'password' =&gt; '1234567890',
            'database' =&gt; 'hogehoge_cakephp',
            'encoding' =&gt; 'utf8',
            'timezone' =&gt; 'UTC',
            'cacheMetadata' =&gt; true,
            'log' =&gt; false,　←　この部分を true に変更します。

            /**
             * Set identifier quoting to true if you are using reserved words or
             * special characters in your table or column names. Enabling this
             * setting will result in queries built using the Query Builder having
             * identifiers quoted when creating SQL. It should be noted that this
             * decreases performance because each query needs to be traversed and
             * manipulated before being executed.
             */
            'quoteIdentifiers' =&gt; false,

            /**
             * During development, if using MySQL &lt; 5.6, uncommenting the * following line could boost the speed at which schema metadata is * fetched from the database. It can also be set directly with the * mysql configuration directive 'innodb_stats_on_metadata = 0' * which is the recommended value in production environments */ //'init' =&gt; ['SET GLOBAL innodb_stats_on_metadata = 0'],
        ],

/home/hogehoge/example.com/public_html/sandbox/app/config

|--Migrations

| |--20190123030101_Initial.php

| |--schema-dump-default.lock

|--Seeds

|--app.default.php

|--app.php　※対象ファイル

|--bootstrap.php

|--bootstrap_cli.php

|--paths.php

|--routes.php

|--schema

| |--i18n.sql

| |--sessions.sql

app.php

/**

* Connection information used by the ORM to connect

* to your application's datastores.

* Drivers include Mysql Postgres Sqlite Sqlserver

* See vendor\cakephp\cakephp\src\Database\Driver for complete list

'Datasources' => [

'default' => [

'className' => 'Cake\Database\Connection',

'driver' => 'Cake\Database\Driver\Mysql',

'persistent' => false,

'host' => 'mysqlxxxx.xserver.jp',

/**

* CakePHP will use the default DB port based on the driver selected

* MySQL on MAMP uses port 8889, MAMP users will want to uncomment

* the following line and set the port accordingly

//'port' => 'nonstandard_port_number',

'username' => 'hogehoge',

'password' => '1234567890',

'database' => 'hogehoge_cakephp',

'encoding' => 'utf8',

'timezone' => 'UTC',

'cacheMetadata' => true,

'log' => false,　←　この部分を true に変更します。

/**

* Set identifier quoting to true if you are using reserved words or

* special characters in your table or column names. Enabling this

* setting will result in queries built using the Query Builder having

* identifiers quoted when creating SQL. It should be noted that this

* decreases performance because each query needs to be traversed and

* manipulated before being executed.

'quoteIdentifiers' => false,

/**

* During development, if using MySQL < 5.6, uncommenting the * following line could boost the speed at which schema metadata is * fetched from the database. It can also be set directly with the * mysql configuration directive 'innodb_stats_on_metadata = 0' * which is the recommended value in production environments */ //'init' => ['SET GLOBAL innodb_stats_on_metadata = 0'],

デバッグログの場所

/home/hogehoge/example.com/public_html/sandbox/app/logs
|--cli-debug.log
|--cli-error.log
|--empty
|--error.log
|--debug.log

/home/hogehoge/example.com/public_html/sandbox/app/logs

|--cli-debug.log

|--cli-error.log

|--empty

|--error.log

|--debug.log

ログの内容

debug.log

2019-01-24 04:52:57 Debug: duration=83 rows=0 SELECT * FROM information_schema.key_column_usage AS kcu
            INNER JOIN information_schema.referential_constraints AS rc
            ON (
                kcu.CONSTRAINT_NAME = rc.CONSTRAINT_NAME
                AND kcu.CONSTRAINT_SCHEMA = rc.CONSTRAINT_SCHEMA
            )
            WHERE kcu.TABLE_SCHEMA = 'prettytabby_cakephp' AND kcu.TABLE_NAME = 'notes' AND rc.TABLE_NAME = 'notes'
2019-01-24 04:52:57 Debug: duration=0 rows=1 SHOW TABLE STATUS WHERE Name = 'notes'
2019-01-24 04:52:57 Debug: duration=0 rows=1 SELECT Users.id AS `Users__id`, Users.name AS `Users__name`, Users.passwd AS `Users__passwd`, Users.status AS `Users__status`, Users.logined_at AS `Users__logined_at`, Users.created AS `Users__created`, Users.modified AS `Users__modified` FROM users Users WHERE Users.id = 1 LIMIT 1
2019-01-24 04:52:57 Debug: duration=0 rows=1 SELECT Bookmarks.id AS `Bookmarks__id`, Bookmarks.user_id AS `Bookmarks__user_id`, Bookmarks.sikaku_kind_id AS `Bookmarks__sikaku_kind_id`, Bookmarks.question_id AS `Bookmarks__question_id`, Bookmarks.created AS `Bookmarks__created`, Bookmarks.modified AS `Bookmarks__modified` FROM bookmarks Bookmarks WHERE Bookmarks.user_id in (1)
2019-01-24 04:52:57 Debug: duration=0 rows=2 SELECT Notes.id AS `Notes__id`, Notes.user_id AS `Notes__user_id`, Notes.note AS `Notes__note`, Notes.created AS `Notes__created`, Notes.modified AS `Notes__modified` FROM notes Notes WHERE Notes.user_id in (1)
2019-01-24 04:53:12 Debug: duration=1 rows=1 SELECT Users.id AS `Users__id`, Users.name AS `Users__name`, Users.passwd AS `Users__passwd`, Users.status AS `Users__status`, Users.logined_at AS `Users__logined_at`, Users.created AS `Users__created`, Users.modified AS `Users__modified` FROM users Users WHERE Users.id = 1 LIMIT 1
2019-01-24 04:53:12 Debug: duration=1 rows=1 SELECT Bookmarks.id AS `Bookmarks__id`, Bookmarks.user_id AS `Bookmarks__user_id`, Bookmarks.sikaku_kind_id AS `Bookmarks__sikaku_kind_id`, Bookmarks.question_id AS `Bookmarks__question_id`, Bookmarks.created AS `Bookmarks__created`, Bookmarks.modified AS `Bookmarks__modified` FROM bookmarks Bookmarks WHERE Bookmarks.user_id in (1)
2019-01-24 04:53:12 Debug: duration=1 rows=2 SELECT Notes.id AS `Notes__id`, Notes.user_id AS `Notes__user_id`, Notes.note AS `Notes__note`, Notes.created AS `Notes__created`, Notes.modified AS `Notes__modified` FROM notes Notes WHERE Notes.user_id in (1)

debug.log

2019-01-24 04:52:57 Debug: duration=83 rows=0 SELECT * FROM information_schema.key_column_usage AS kcu

INNER JOIN information_schema.referential_constraints AS rc

ON (

kcu.CONSTRAINT_NAME = rc.CONSTRAINT_NAME

AND kcu.CONSTRAINT_SCHEMA = rc.CONSTRAINT_SCHEMA

)

WHERE kcu.TABLE_SCHEMA = 'prettytabby_cakephp' AND kcu.TABLE_NAME = 'notes' AND rc.TABLE_NAME = 'notes'

2019-01-24 04:52:57 Debug: duration=0 rows=1 SHOW TABLE STATUS WHERE Name = 'notes'

2019-01-24 04:52:57 Debug: duration=0 rows=1 SELECT Users.id AS `Users__id`, Users.name AS `Users__name`, Users.passwd AS `Users__passwd`, Users.status AS `Users__status`, Users.logined_at AS `Users__logined_at`, Users.created AS `Users__created`, Users.modified AS `Users__modified` FROM users Users WHERE Users.id = 1 LIMIT 1

2019-01-24 04:52:57 Debug: duration=0 rows=1 SELECT Bookmarks.id AS `Bookmarks__id`, Bookmarks.user_id AS `Bookmarks__user_id`, Bookmarks.sikaku_kind_id AS `Bookmarks__sikaku_kind_id`, Bookmarks.question_id AS `Bookmarks__question_id`, Bookmarks.created AS `Bookmarks__created`, Bookmarks.modified AS `Bookmarks__modified` FROM bookmarks Bookmarks WHERE Bookmarks.user_id in (1)

2019-01-24 04:52:57 Debug: duration=0 rows=2 SELECT Notes.id AS `Notes__id`, Notes.user_id AS `Notes__user_id`, Notes.note AS `Notes__note`, Notes.created AS `Notes__created`, Notes.modified AS `Notes__modified` FROM notes Notes WHERE Notes.user_id in (1)

2019-01-24 04:53:12 Debug: duration=1 rows=1 SELECT Users.id AS `Users__id`, Users.name AS `Users__name`, Users.passwd AS `Users__passwd`, Users.status AS `Users__status`, Users.logined_at AS `Users__logined_at`, Users.created AS `Users__created`, Users.modified AS `Users__modified` FROM users Users WHERE Users.id = 1 LIMIT 1

2019-01-24 04:53:12 Debug: duration=1 rows=1 SELECT Bookmarks.id AS `Bookmarks__id`, Bookmarks.user_id AS `Bookmarks__user_id`, Bookmarks.sikaku_kind_id AS `Bookmarks__sikaku_kind_id`, Bookmarks.question_id AS `Bookmarks__question_id`, Bookmarks.created AS `Bookmarks__created`, Bookmarks.modified AS `Bookmarks__modified` FROM bookmarks Bookmarks WHERE Bookmarks.user_id in (1)

2019-01-24 04:53:12 Debug: duration=1 rows=2 SELECT Notes.id AS `Notes__id`, Notes.user_id AS `Notes__user_id`, Notes.note AS `Notes__note`, Notes.created AS `Notes__created`, Notes.modified AS `Notes__modified` FROM notes Notes WHERE Notes.user_id in (1)

このように、CakePHPでは、設定ファイルを変更することで、簡単にデバッグログを出力することができます。

開発中には、ログ出力の設定を有効にし、開発の効率が格段にアップするはずです。

是非、参考にして下さい。