[Laravel]DB::getQueryLog()が返すtimeの単位は何? (ミリ秒)

Illuminate/DatabaseパッケージのgetQueryLog()は、実行されたSQLとパラメータに加えて、処理時間をtimeのキーで取得できます。手元の環境で1～2ぐらいの値が帰ってくるので絶対ミリ秒単位だろうと思ったのですが、気になったので調べました。

結果を先に書くと、ミリ秒単位で正解でした。

例えば、取得した値がtime=4.12なら4.12ミリ秒(=0.00412秒)を意味します。

確認した結果

まずgetQueryLog()が返す値ですがprivateメンバ変数である$this->queryLogの値をそのまま返しています。

// Illuminate/Database/Connection.php
class Connection implements ConnectionInterface
    /**
     * Get the connection query log.
     *
     * @return array
     */
    public function getQueryLog()
    {
        return $this->queryLog;
    }

$this->queryLogは、どこでセットしているかというと、同じクラスのlogQuery()メソッドです。
第3引数で渡された値を、連想配列としてそのままセットしています。

    /**
     * Log a query in the connection's query log.
     *
     * @param  string  $query
     * @param  array   $bindings
     * @param  float|null  $time
     * @return void
     */
    public function logQuery($query, $bindings, $time = null)
    {
        $this->event(new QueryExecuted($query, $bindings, $time, $this));
        if ($this->loggingQueries) {
            $this->queryLog[] = compact('query', 'bindings', 'time');
        }
    }

さらに、logQuery()の予備元を確認するとrun()メソッドでした。
ここでgetElapsedTime()メソッドの戻り値を第3引数に渡しています。

    protected function run($query, $bindings, Closure $callback)
    {
        ...
        // the event that the developer needs them. We'll log time in milliseconds.
        $this->logQuery(
            $query, $bindings, $this->getElapsedTime($start)
        );
        ...
    }

最終的にたどり着いたのがgetElapsedTime()メソッドです

    /**
     * Get the elapsed time since a given starting point.
     *
     * @param  int    $start
     * @return float
     */
    protected function getElapsedTime($start)
    {
        return round((microtime(true) - $start) * 1000, 2);
    }

getElapsedTime()メソッドは、時間の計算にmicrotime(true)を利用しています。microtime(true)は現在のunixtimeをマイクロ秒単位の精度で返してくれる関数で数値の1が1秒に相当します。

取得した値を1000倍しているので単位は"ミリ秒"が正解でした。また小数点以下2桁で切っているので、精度は0.01ミリ秒単位です。

Amazonでおトクに買い物する方法