Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Log all executed lines

Tags:

php

Is there a simple way (short of sticking fwrites after every line) of getting PHP to write every executed line to a log?

like image 984
Ben Williams Avatar asked Jun 09 '11 14:06

Ben Williams


1 Answers

Although I agree with @gnif because a debugger is best suited for that, I'll still answer your question, because it is possible (not perfect, but possible).

Consider you have the following code:

sometest.php

<?php

declare(ticks=1);

include_once 'debug.php';

$a = 'foo';
$b = 'bar';
$c = $a . $b;
$d = $e = "hello";
strlen($d);

include 'somefile.php';

somefile.php

<?php

$hello = 'world';

So, sometest.php includes the following file (debug.php):

<?php

register_tick_function(function(){
    $backtrace = debug_backtrace();
    $line = $backtrace[0]['line'] - 1;
    $file = $backtrace[0]['file'];

    if ($file == __FILE__) return;

    static $fp, $cur, $buf;
    if (!isset($fp[$file])) {
        $fp[$file] = fopen($file, 'r');
        $cur[$file] = 0;
    }

    if (isset($buf[$file][$line])) {
        $code = $buf[$file][$line];
    } else {
        do {
            $code = fgets($fp[$file]);
            $buf[$file][$cur[$file]] = $code;
        } while (++$cur[$file] <= $line);
    }

    $line++;
    echo "$code called in $file on line $line\n";
});

It registers a tick function, and also declares the tick interval. It will keep track of the files/lines that are invoked using the backtrace.

Now, if we execute sometest.php, we'll get:

include_once 'debug.php';
 called in sometest.php on line 5
$a = 'foo';
 called in sometest.php on line 7
$b = 'bar';
 called in sometest.php on line 8
$c = $a . $b;
 called in sometest.php on line 9
$d = $e = "hello";
 called in sometest.php on line 10
strlen($d);
 called in sometest.php on line 11
$hello = 'world';
 called in somefile.php on line 3
include 'somefile.php';
 called in sometest.php on line 13

You can see that the somefile.php include is at the very end, even though it's called before $hello = 'world'. This is because the tick function will be called when the include finishes for that line, not when it starts.

Also, the tick function is called in function/methods declaration:

<?php

function foo() {
    return 'bar';
}

foo();

Would give you something like:

}
 called in somefunc.php on line 5   # this is the function declaration
foo();
 called in somefunc.php on line 7   # this is the function call

Note: Be careful when using ticks, because before 5.3.0, it was not supported in threaded web servers.

like image 85
netcoder Avatar answered Oct 15 '22 19:10

netcoder