Why did we install log4? by Alena

You may be wondering – “why do we need log4php?’
I will try to answer this question in this post in just a moment – cognition comes through comparison.

No matter what format of logs we will decide to use (JSON, Test Anything Protocol or XML) – PHPUnit will only report to us, one of the following return states :

. – Test succeeded
F – Assertion Fails
E – Error
S – Skipped
I – Incomplete

These may seem rather brief, but for a person running the tests through PHPUnit, this level of feedback should be enough.

But we are not the people running the tests, we are writers. :)

What does a writer need? A writer needs an effective output from each line of code. Did the variables initialize? Did a given function return the correct value? Which branch algorithm did it choose? All of these things are of interest to the writer. To fulfil such curiosity, the test writers of the PHP team (humbly, me) decided to use log4php.

For example – one needs to test a page. Testing starts with a check which counts all elements that should be there.
From logging point of view, this can be performed in two ways.



Method 1 (using only PHPUnit logging facility)

<?php
   // ...
   class simpleTest extends PHPUnit_Framework_TestCase {
      // declared and initialised variables $selenium
      public function testElementsPresence() {
         // ...
         $this->assertTrue(
             $this->selenium->isElementPresent("element1"),
             "Element _element1_ is not present"
         );
         $this->assertTrue(
             $this->selenium->isElementPresent("element2"),
             "Element _element2_ is not present"
         );
         $this->assertTrue(
             $this->selenium->isElementPresent("element3"),
             "Element _element3_ is not present"
         );
         // ...
   }
?>

Let’s assume that first and third elements are missing on a page we test. This is what we will see in log file:

C:\SimpleTest\PHP>phpunit simpleTest.php
PHPUnit 3.3.9 by Sebastian Bergmann.

F

Time: 15 seconds

There was 1 failure:

1) testSimple(simpleTest)
Element _element1_ is not present
Failed asserting that is true.
C:SimpleTestPHPsimpleTest.php:35

FAILURES!
Tests: 1, Assertions: 1, Failures: 1.

Looking into the output, we notice that the first element was caught and reported by test but the missing third element was overlooked. If we wanted to check ALL of the elements on a page, we failed to achieve it with PHPUnit logging alone.

Method 2 (adding the log4php facility)

<?php
   // ...
   class simpleTest extends PHPUnit_Framework_TestCase {
      // declared and initialised variables $selenium and $logger
      public function testSimple() {
         // ...
         $elementsPresent = TRUE;
         if (!$this->selenium->isElementPresent("element1")) {
            $elementsPresent = FALSE;
            $this->logger->error("Element _element1_ is not present");
         }
         if (!$this->selenium->isElementPresent("element2")) 
            $elementsPresent = FALSE;
            $this->logger->error("Element _element2_ is not present");
         }
         if (!$this->selenium->isElementPresent("element3")) 
            $elementsPresent = FALSE;
            $this->logger->error("Element _element3_ is not present");
         }
         // here test will fail if $elementsPresent != TRUE
         $this->assertTrue($elementsPresent, "Not all elements are present");
         // ...
   }
?>

We are testing the same page where the first and third elements are missing. As a result of the test execution our logs will look like this:

С:\SimpleTest\PHP>phpunit simpleTest.php
PHPUnit 3.3.9 by Sebastian Bergmann.

// next two lines - log4php output
ERROR - Element _element1_ is not present
ERROR - Element _element3_ is not present
F

// from next line - PHPUnit output

Time: 15 seconds

There was 1 failure:

1) testSimple(simpleTest)
Not all elements are present.
Failed asserting that is true.
C:SimpleTestPHPsimpleTest.php:52

FAILURES!
Tests: 1, Assertions: 1, Failures: 1.

We can see that test fully executed and did not stop after first non existent element, it just outputs a message and sets flag $elementsPresent to FALSE. After all elements checked – this flag checked to signal if test succeeded or failed.

With this approach a tester executing it will have all elements checked. In Method 2 PHPUnit and log4php worked together – PHPUnit pronounced a problem in general (Not all elements are present) and log4php brought necessary convenient detalisation (ERROR – Element _element1_ is not present and ERROR – Element _element2_ is not present).
This is why, after taking in account all above, we can be quite sure in advantages of using log4php in conjunction with PHPUnit logging within the same test to produce the most detailed error report for our testing.

Enjoy your logging! :)

Mar 17th, 2009 by Dima

Just for your information, I would like to remind everyone that TestNG doesn’t limit us to logging assert failures to the logs, we can log but whatever information we want. This mechanism exists but I found it awkward to use.


Print this post | Home

8 comments

  1. Blockhead says:

    как вам удалось перехватить плохие действия в тесте?
    Если я напишу:

    if(!$this->selenium->click(“link=test”))
    $this->logger->err(‘TestErr’);

    У меня не выводится TestErr на экран(
    Пишет что то типа:
    Testing_Selenium_Exception: The Response of the Selenium RC is invalid: ERROR: E
    lement link=test not found

  2. Blockhead says:

    Вообще как сделать так чтобы при неудачном тестировании вызывалась определенная функция? Это возможно?

  3. bear says:

    Blockhead,
    Если нет элемента с локатором “link=test”, selenium->click() вызовет исключение. Поэтому до строки с записью в лог дело, конечно, не дойдёт.
    Как можно с этим бороться?
    1) перед выполнением click() проверить, что элемент имеется, с помощью isElementPresent().
    2) ловить сгенерённое исключение и обрабатывать его.

    Это также и ответы на вопрос про вызов определённой функции: для 1) надо её вызвать, если элемент не найден, для 2) – вызывать в обработчике исключения.

    Как обрабатываются исключения – можете посмотреть, вытащив из SVN PHP версию тестов, отсюда:
    http://deepshiftlabs.com/svn/tests/trunk/salesforce/php.
    В файле seleniumActions.php найдётся много примеров ). Этот класс как раз сожержит обёртки для методов Selenium, которые обрабатывают прерывания.

  4. Blockhead says:

    A vozmozno ese napisat’ stat’iu pro TestListener?)) Это вроде как решение данной проблемы
    http://www.phpunit.de/manual/current/en/extending-phpunit.html#extending-phpunit.PHPUnit_Framework_TestListener

  5. Blockhead says:

    Variant s isElementPresent() ne podoidet t.k. esli naprimer ne srabotaet funksia “open” v selenium, otlovit’ osibku ne udastsa(

  6. bear says:

    Это точно, поэтому в seleniumActions.php все методы Selenium вызываются внутри try{} блока. Это самый надёжный способ, но isElementPresent() в описанном выше случае позволит отловить ошибку и понять её причину, не доводя дело до исключений.

    Что касается TestListener – мы никогда не работали с этим классом, поэтому как минимум в ближайшее время написать статью точно не получится.

  7. Blockhead says:

    Ну хотябы кратко описать установку расширений классов возможно?

  8. bear says:

    По ссылке, которая была приведена, есть ссылка на пример использования:
    “In the section called “Test Listeners” you can see how to configure PHPUnit to attach your test listener to the test execution.”.