スタックトレースを出力する

プログラムのデバッグをする際、スタックトレースを用いれば、呼び出し箇所を容易に特定できます。

その出力方法です。

debug_backtrace()関数を使用します。

公式ドキュメントはこちら。

このように使用して出力します。

$backtrace = debug_backtrace();

foreach ($backtrace as $item) {
    $file = array_key_exists('file', $item)
        ? $item['file']
        : '';
    $line = array_key_exists('line', $item)
        ? $item['line']
        : '';
    $class = array_key_exists('class', $item)
        ? $item['class']
        : '';
    $type = array_key_exists('type', $item)
        ? $item['type']
        : '';
    $function = $item['function'];
    error_log(
        sprintf(
            __METHOD__ ." %s:%d %s%s%s"
            , $file
            , $line
            , $class
            , $type
            , $function
        )
    );
}

$backtrace = debug_backtrace();

foreach ($backtrace as $item) {

$file = array_key_exists('file', $item)

? $item['file']

: '';

$line = array_key_exists('line', $item)

? $item['line']

: '';

$class = array_key_exists('class', $item)

? $item['class']

: '';

$type = array_key_exists('type', $item)

? $item['type']

: '';

$function = $item['function'];

error_log(

sprintf(

__METHOD__ ." %s:%d %s%s%s"

, $file

, $line

, $class

, $type

, $function

)

);

}

__METHOD__ 定数を利用している理由は、この処理を組み込んだ箇所を忘れないようにする為です。

実行結果の例を以下に記します。

これはLumen フレームワークを用いたアプリケーションで、Illuminate\Database\Connection::runQueryCallback()メソッドの呼び出し経路を、Log ファサードのdebug()メソッドを利用して出力したものです。

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/database/Connection.php:625 Illuminate\Database\Connection->runQueryCallback
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/database/Connection.php:334 Illuminate\Database\Connection->run
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/database/Query/Builder.php:1963 Illuminate\Database\Connection->select
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/database/Query/Builder.php:1951 Illuminate\Database\Query\Builder->runSelect
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/database/Query/Builder.php:2435 Illuminate\Database\Query\Builder->Illuminate\Database\Query\{closure}
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/database/Query/Builder.php:1952 Illuminate\Database\Query\Builder->onceWithColumns
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/database/Eloquent/Builder.php:481 Illuminate\Database\Query\Builder->get
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/database/Eloquent/Builder.php:465 Illuminate\Database\Eloquent\Builder->getModels
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/database/Concerns/BuildsQueries.php:77 Illuminate\Database\Eloquent\Builder->get
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/app/Http/Controllers/Controller.php:34 Illuminate\Database\Eloquent\Builder->first
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback :0 App\Http\Controllers\Controller->show
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/container/BoundMethod.php:29 call_user_func_array
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/container/BoundMethod.php:87 Illuminate\Container\BoundMethod::Illuminate\Container\{closure}
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/container/BoundMethod.php:31 Illuminate\Container\BoundMethod::callBoundMethod
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/container/Container.php:564 Illuminate\Container\BoundMethod::call
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/laravel/lumen-framework/src/Concerns/RoutesRequests.php:373 Illuminate\Container\Container->call
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/laravel/lumen-framework/src/Concerns/RoutesRequests.php:339 Laravel\Lumen\Application->callControllerCallable
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/laravel/lumen-framework/src/Concerns/RoutesRequests.php:313 Laravel\Lumen\Application->callLumenController
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/laravel/lumen-framework/src/Concerns/RoutesRequests.php:275 Laravel\Lumen\Application->callControllerAction
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/laravel/lumen-framework/src/Concerns/RoutesRequests.php:260 Laravel\Lumen\Application->callActionOnArrayBasedRoute
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/laravel/lumen-framework/src/Concerns/RoutesRequests.php:160 Laravel\Lumen\Application->handleFoundRoute
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback :0 Laravel\Lumen\Application->Laravel\Lumen\Concerns\{closure}
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/laravel/lumen-framework/src/Routing/Pipeline.php:52 call_user_func
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback :0 Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/laravel/lumen-framework/src/Routing/Pipeline.php:32 call_user_func
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback :0 Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/laravel/lumen-framework/src/Routing/Pipeline.php:32 call_user_func
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/pipeline/Pipeline.php:104 Laravel\Lumen\Routing\Pipeline->Laravel\Lumen\Routing\{closure}
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/laravel/lumen-framework/src/Concerns/RoutesRequests.php:410 Illuminate\Pipeline\Pipeline->then
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/laravel/lumen-framework/src/Concerns/RoutesRequests.php:166 Laravel\Lumen\Application->sendThroughPipeline
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/laravel/lumen-framework/src/Concerns/RoutesRequests.php:107 Laravel\Lumen\Application->dispatch
[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/public/index.php:28 Laravel\Lumen\Application->run

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/database/Connection.php:625 Illuminate\Database\Connection->runQueryCallback

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/database/Connection.php:334 Illuminate\Database\Connection->run

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/database/Query/Builder.php:1963 Illuminate\Database\Connection->select

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/database/Query/Builder.php:1951 Illuminate\Database\Query\Builder->runSelect

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/database/Query/Builder.php:2435 Illuminate\Database\Query\Builder->Illuminate\Database\Query\{closure}

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/database/Query/Builder.php:1952 Illuminate\Database\Query\Builder->onceWithColumns

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/database/Eloquent/Builder.php:481 Illuminate\Database\Query\Builder->get

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/database/Eloquent/Builder.php:465 Illuminate\Database\Eloquent\Builder->getModels

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/database/Concerns/BuildsQueries.php:77 Illuminate\Database\Eloquent\Builder->get

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/app/Http/Controllers/Controller.php:34 Illuminate\Database\Eloquent\Builder->first

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback :0 App\Http\Controllers\Controller->show

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/container/BoundMethod.php:29 call_user_func_array

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/container/BoundMethod.php:87 Illuminate\Container\BoundMethod::Illuminate\Container\{closure}

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/container/BoundMethod.php:31 Illuminate\Container\BoundMethod::callBoundMethod

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/container/Container.php:564 Illuminate\Container\BoundMethod::call

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/laravel/lumen-framework/src/Concerns/RoutesRequests.php:373 Illuminate\Container\Container->call

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback :0 Laravel\Lumen\Application->Laravel\Lumen\Concerns\{closure}

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/laravel/lumen-framework/src/Routing/Pipeline.php:52 call_user_func

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback :0 Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/laravel/lumen-framework/src/Routing/Pipeline.php:32 call_user_func

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback :0 Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/laravel/lumen-framework/src/Routing/Pipeline.php:32 call_user_func

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/vendor/illuminate/pipeline/Pipeline.php:104 Laravel\Lumen\Routing\Pipeline->Laravel\Lumen\Routing\{closure}

[2019-02-01 22:00:05] development.DEBUG: Illuminate\Database\Connection::runQueryCallback /var/www/public/index.php:28 Laravel\Lumen\Application->run

私はフレームワークの拡張を行う際に、このような調査をよく行っています。

例えば、

Aクラスを継承し、BメソッドをオーバーライドしたCクラスを作成
Aクラスの生成箇所を特定
そこをCクラスのインスタンス生成処理と変更

このような生成処理を行っている箇所を特定する場合等です。

プログラミングPHP 第3版

posted with ヨメレバ

Kevin Tatroe,Peter MacIntyre,Rasmus Lerdorf オライリージャパン 2014-03-25

宮崎県在住。
プログラムを書いて暮らしています。趣味はルアーフィッシング、ギター。

ktykwsk.com

スタックトレースを出力する

関連記事

釣行記録や釣りに関する話題、プログラムやコンピュータの備忘録、日々の暮らしなどなど…。