Search code examples
zend-frameworkseleniumphpunitcode-coverage

PHPUnit Selenium RC test coverage works for GET but not POST requests?

I've inherited a Zend Framework web application that is neither object-oriented nor well-written in many respects, and it came with zero tests. So while I appreciate the value of unit tests, and will write them as I add or re-write code, functional tests with code coverage seems like the best place to start. It also makes a great learning tool for understanding how the application works. This is Zend Framework 1.11, and Matthew Weier O'Phinney has stated that Zend_Test only works with PHPUnit up through 3.4. So I installed the latest 3.4.15. I've verified that I can extend Zend_Test_PHPUnit_ControllerTestCase and do unit testing on controllers that way.

For functional testing through Selenium, I had some trouble getting code coverage to work. In fact I doubted that it was technically feasible to get coverage data given the way that the Selenium server works, but with help from Does PHPUnit_Selenium Code Coverage Work? and Does PHPUnit_Selenium Code Coverage Work? I finally got it working with my application. It's great being able to see what parts of the code are hit by different requests!

But the problem I'm now seeing is that the code handling POST requests doesn't seem to get reported.

For example in a controller I have a contactAction method with code like this:

$this->view->form = $form;
 if ($this->getRequest()->isPost()) {
   if ($form->isValid($this->getRequest()->getPost())) {
     $values = $form->getValues();

This is for a Contact Us form. In a Selenium test I open the url, type the message, click the submit button, and wait for the page load. When I run the test I can see this happen in the browser, and receive the email with the message that was typed by selenium, so I'm certain that the form was posted with valid data, and that the second two lines did execute. But in the coverage report, the first two lines are green, and the second two are orange.

I instrumented both the prepend.php and append.php scripts to log the following information:

     "(File: " . __FILE__ . "): REQUEST_METHOD: " . $_SERVER['REQUEST_METHOD'] . "\n" .
     "REQUEST_URI: " . $_SERVER['REQUEST_URI'] . "\n" .
     "_COOKIE['PHPUNIT_SELENIUM_TEST_ID']: '" . print_r(isset($_COOKIE['PHPUNIT_SELENIUM_TEST_ID']), 1) . "'\n" .
     "_GET['PHPUNIT_SELENIUM_TEST_ID']: '" . print_r(isset($_GET['PHPUNIT_SELENIUM_TEST_ID']), 1) . "'\n" .
     "_POST['PHPUNIT_SELENIUM_TEST_ID']: '" . print_r(isset($_POST['PHPUNIT_SELENIUM_TEST_ID']), 1) . "'\n" .

One odd thing is that only the prepend script ever gets logged, never the append script. I have no idea why, but it doesn't seem to affect the coverage data (for GET requests at least). The only thing I've seen that might explain it is if the Zend MVC app ends with an exit()? Does that make sense?

Here is what gets logged for the contact us interaction:

(File C:\xampp\htdocs\myapp\public\prepend.php): REQUEST_METHOD: GET
REQUEST_URI: /index/contact
_COOKIE['PHPUNIT_SELENIUM_TEST_ID']: '1'
_GET['PHPUNIT_SELENIUM_TEST_ID']: ''
_POST['PHPUNIT_SELENIUM_TEST_ID']: ''
extension_loaded('xdebug'): '1'

(File C:\xampp\htdocs\myapp\public\prepend.php): REQUEST_METHOD: GET
REQUEST_URI: /index/contact
_COOKIE['PHPUNIT_SELENIUM_TEST_ID']: '1'
_GET['PHPUNIT_SELENIUM_TEST_ID']: ''
_POST['PHPUNIT_SELENIUM_TEST_ID']: ''
extension_loaded('xdebug'): '1'

(File C:\xampp\htdocs\myapp\public\prepend.php): REQUEST_METHOD: POST
REQUEST_URI: /index/contact
_COOKIE['PHPUNIT_SELENIUM_TEST_ID']: '1'
_GET['PHPUNIT_SELENIUM_TEST_ID']: ''
_POST['PHPUNIT_SELENIUM_TEST_ID']: ''
extension_loaded('xdebug'): '1'

(File C:\xampp\htdocs\myapp\public\prepend.php): REQUEST_METHOD: GET
REQUEST_URI: /default/index/contact
_COOKIE['PHPUNIT_SELENIUM_TEST_ID']: '1'
_GET['PHPUNIT_SELENIUM_TEST_ID']: ''
_POST['PHPUNIT_SELENIUM_TEST_ID']: ''
extension_loaded('xdebug'): '1'

(File C:\xampp\htdocs\myapp\public\prepend.php): REQUEST_METHOD: GET
REQUEST_URI: /default/index/contact
_COOKIE['PHPUNIT_SELENIUM_TEST_ID']: '1'
_GET['PHPUNIT_SELENIUM_TEST_ID']: ''
_POST['PHPUNIT_SELENIUM_TEST_ID']: ''
extension_loaded('xdebug'): '1'

(File C:\xampp\htdocs\myapp\public\prepend.php): REQUEST_METHOD: GET
REQUEST_URI: /phpunit_coverage.php?PHPUNIT_SELENIUM_TEST_ID=a85030b0bcdb0460bfb17a83a373d6b5
_COOKIE['PHPUNIT_SELENIUM_TEST_ID']: ''
_GET['PHPUNIT_SELENIUM_TEST_ID']: '1'
_POST['PHPUNIT_SELENIUM_TEST_ID']: ''
extension_loaded('xdebug'): '1'

As you can see, the GET requests get logged twice, and the POST only once. Perhaps that is related to the fact that only the GET requests seem to get covered while the POSTS don't? But I really don't understand this behavior in several ways, and I'm at a loss for what to do to help figure it out.

Anybody got any ideas either about why I'm not getting coverage for the POST requests, or what the next step might be to track it down?

Solution

  • In the question, I speculated that maybe if the Zend Framework was calling exit(), that might explain why the append.php script never got logged. So I searched the entire source of the ZF library for calls to exit(), and found only three:

    library/Zend/Controller/Action/Helper/Redirector.php:        exit();
library/Zend/Oauth/Consumer.php:        exit(1);
library/Zend/OpenId.php:            exit();

    There was no use of Oauth or OpenId in this scenario. But as I noted in the comment the POST request code showed coverage when login failed and the form got redisplayed, but not when it succeeded and a redirect to the welcome page happened. So the redirector looked like the place to check.

    For redirection, the code in the action routines of this application uniformly use:

    $this->_redirect("some-url");

    and I never investigated how it works or any options on it because it's never been a problem. But with the possibility of its causing the coverage problem, I read its documentation and browsed the Zend source code. I found that there is a simple option to cause redirection not to call exit(). So I changed the ones in question to:

    return $this->_redirect("some-url", array('exit'=>false));

    And voila, the missing code coverage for the POST request showed up!

    Now I'm wondering if I should just override _redirect so that it always suppresses the exit call, or if I should only do that in the testing environment. I guess terminating the script immediately on a redirect might save some cycles in production.

    So the main problem is solved. But the mystery remains that the logging code I put in the append.php script still doesn't produce any output - the prepend.php script always produces its log output, but never append.php. It was the absence of output from append.php that put me on the trail of an exit() call within ZF, but it seems that there is some other reason that the output is not produced.

    And I finally figured this one out, too. It was simply a typo in the append script. I couldn't believe it because I "knew" the logging code that I added to append.php was identical to the code in prepend.php, having done a copy-paste from prepend to append. But apparently I fat-fingered the select on the copy, and missed the last line of the message text. When I finally saw the missing line, my first reaction was "That's not possible, I should have gotten a syntax error, not just a lack of output." Here's the code as I expected it to be:

    $msg ="\n(File " . __FILE__ . "): REQUEST_METHOD: " . $_SERVER['REQUEST_METHOD'] . "\n" .
         "REQUEST_URI: " . $_SERVER['REQUEST_URI'] . "\n" .
         "_COOKIE['PHPUNIT_SELENIUM_TEST_ID']: '" . print_r(isset($_COOKIE['PHPUNIT_SELENIUM_TEST_ID']), 1) . "'\n" .
         "_GET['PHPUNIT_SELENIUM_TEST_ID']: '" . print_r(isset($_GET['PHPUNIT_SELENIUM_TEST_ID']), 1) . "'\n" .
         "_POST['PHPUNIT_SELENIUM_TEST_ID']: '" . print_r(isset($_POST['PHPUNIT_SELENIUM_TEST_ID']), 1) . "'\n" .
         "extension_loaded('xdebug'): '". print_r(extension_loaded('xdebug'), 1) . "'\n";
file_put_contents($GLOBALS['PHPUNIT_COVERAGE_DATA_DIRECTORY'] . "/msg.log", $msg, FILE_APPEND);

    But I accidentally missed the final line of the assignment to $msg. So when I realized it was missing, and saw the dangling string concatenation operator on the line before the call to file_put_contents(), at first I was puzzled that I didn't get a syntax error. But of course php is quite happy to call file_put_contents() with the old value of $msg (the value assigned in the prepend script), and append its result (the number of bytes written) to the string assigned to $msg (which then is never used)! Nothing actually surprising when you see the code accurately, but incredibly mysterious when your mind is clouded by assuming that your copy-paste of correct code could not possibly have gone wrong!