04: Debugging failed tests

So far we've learned how to create .phpt tests and run them with run-test.php. But what do we do when a test fails? Today we dig in and debug failed tests.

Make a test fail

We started by making our trusty echo_basic.phpt test fail by appending a smile emoticon to the end of the --EXPECT-- section and looked at each of the files that run-tests creates when a test fails.

$ make test TESTS=echo_basic.phpt
$ ls | grep echo
echo_basic.diff
echo_basic.exp
echo_basic.log
echo_basic.out
echo_basic.php
echo_basic.phpt
echo_basic.sh

.out The actual output that the PHP code from the --FILE-- section generated
.exp The output we expected from the --EXPECT-- section
.diff A diff file with the actual output compared to the expected output
.log Both actual and expected output in one file
.php The --FILE-- section as a PHP file
.sh A bash script that runs the PHP file in the same environment that run-tests ran it (more on this later)

Create a more complex example

In order to see the power of the .sh file that gets generated, we created a more complicated test.

$ vi upload_ini_basic.phpt

--TEST--
upload_max_filesize basic test
--INI--
upload_max_filesize=1337M
--FILE--
<?php
$max = ini_get('upload_max_filesize');
echo "Your max upload is {$max}\n";
?>
--EXPECT--
Your max upload is 1337M

If we run it through run-tests, it passes.

$ make test TESTS=upload_ini_basic.phpt

But when we run it as a plain-old PHP file, we see it outputs unexpected output in the --FILE-- section.

$ sapi/cli/php upload_ini_basic.phpt
--TEST--
upload_max_filesize basic test
--INI--
upload_max_filesize=1337M
--FILE--
Your max upload is 2M
--EXPECT--
Your max upload is 1337M

The --FILE-- part outputs "Your max upload is 2M" which is not what we want. So why did it pass in run-tests? Because we added the --INI-- section which run-tests will parse and set any ini settings for us.

Seeing what run-tests sees

Sometime it's handy to see what run-tests sees right in the console so we checked for output options using --help on run-tests.

$ sapi/cli/php run-tests.php --help

We saw that we could use the --show-all flag to output what run-tests sees straight to the console. But since we're running the tests through make, we didn't have a way to pass in the flag.

So we looked at the Makefile and saw that the TESTS variable was just being appended to the end of the command that executes run-tests, so we just added the flag to the TESTS variable.

$ make test TESTS="--show-all upload_ini_basic.phpt"

Doing this we can see that run-tests clearly sees the expected, "Your max upload is 1337M" output in the PHP code.

Running the test as run-tests ran it

We made the test fail by appending another smile face at the end of the --EXPECT-- section and looked at the output files that run-tests generated.

$ make test TESTS=upload_ini_basic.phpt
$ ls | grep upload
upload_ini_basic.diff
upload_ini_basic.exp
upload_ini_basic.log
upload_ini_basic.out
upload_ini_basic.php
upload_ini_basic.phpt
upload_ini_basic.sh

We compared running the plain-old PHP file with the bash script to see that the bash script runs the test in the same environment that run-tests ran the script.

$ sapi/cli/php upload_ini_basic.php
Your max upload is 2M
$ ./upload_ini_basic.sh
Your max upload is 1337M

Debugging with gdb

Next we learned how to debug the PHP source code with gdb.

We used cat to dump the contents of upload_ini_basic.sh to the screen and copied the big long command on line 3.

$ cat upload_ini_basic.sh

Then we pasted in the command using the --args flag with gdb.

$ gdb --args [paste command here]

After pressing enter to continue we typed run in gdb to see our program run within gdb.

We first set a breakpoint in the compiler for echo by typing break zend_compile_echo in gdb and then typed run to see our program stop at zend_compile_echo().

We typed a few commands in gdb to move about the program.

list Show a few lines of code above and below where we are currently stopped to see some context
next Go to the next line of code in the current context
print var Dump a var onto the screen for inspection
c Continue until hitting the next breakpoint or end of program
info breakpoints Show all the set breakpoints
delete 1 Deletes breakpoint 1 (number discovered from the output of info breakpoints)
break ext/standard/basic_functions.c:5309 Set a breakpoint in basic_functions.c on line 5309

Resources

Analyzing failing tests
Take part in PHP TestFest 2017
I'll be giving talks about writing tests for PHP source at NEPHP 2017 and ZendCon 2017. Join me! :)
The Docker setup I used in these screencasts