Monday, April 23, 2012

Logging Selenium WebDriver


With Selenium Webdriver version 2.15.0 logging is enabled to help the debugging. By default logging is enabled. Just add a logger to get the logs.

Setting log level is also easy. Set in the logger or use this code

((RemoteWebDriver) driver).setLogLevel(ALL);

As this helps in debugging however, in latest version there is a change in the log output. In 2.15 out put is shown below,

Jan 13, 2012 5:42:00 AM org.openqa.selenium.remote.RemoteWebDriver execute
INFO: Executing: [null, newSession {"desiredCapabilities":"Capabilities [{platform=WINDOWS, ensureCleanSession=true, browserName=internet explorer, version=}]"}]
Jan 13, 2012 5:42:16 AM org.apache.http.impl.client.DefaultRequestDirector tryExecute
INFO: I/O exception (java.net.SocketException) caught when processing request: Software caused connection abort: recv failed
Jan 13, 2012 5:42:16 AM org.apache.http.impl.client.DefaultRequestDirector tryExecute
INFO: Retrying request
Jan 13, 2012 5:42:16 AM org.openqa.selenium.remote.RemoteWebDriver execute
INFO: Executing: [e36c6b06-ab81-4daf-b99a-1af8cbc138cd, implicitlyWait {"ms":300000}]
Jan 13, 2012 5:42:17 AM org.openqa.selenium.remote.RemoteWebDriver execute
INFO: Executing: [e36c6b06-ab81-4daf-b99a-1af8cbc138cd, get {"url":"https://test.com/"}]
Jan 13, 2012 5:42:54 AM org.openqa.selenium.remote.RemoteWebDriver execute
INFO: Executing: [e36c6b06-ab81-4daf-b99a-1af8cbc138cd, getCurrentWindowHandle {}]
Jan 13, 2012 5:42:54 AM org.openqa.selenium.remote.RemoteWebDriver execute
INFO: Executing: [e36c6b06-ab81-4daf-b99a-1af8cbc138cd, getCurrentWindowHandle {}]
353b31e2-046e-403f-96da-4f520163d341
Jan 13, 2012 5:42:54 AM org.openqa.selenium.remote.RemoteWebDriver execute
INFO: Executing: [e36c6b06-ab81-4daf-b99a-1af8cbc138cd, switchToFrame {"id":0}]
Jan 13, 2012 5:42:54 AM org.openqa.selenium.remote.RemoteWebDriver execute
INFO: Executing: [e36c6b06-ab81-4daf-b99a-1af8cbc138cd, findElement {"using":"name","value":"a"}]
Jan 13, 2012 5:43:18 AM org.openqa.selenium.remote.RemoteWebDriver execute
INFO: Executing: [e36c6b06-ab81-4daf-b99a-1af8cbc138cd, findElement {"using":"name","value":"b"}]
Jan 13, 2012 5:43:18 AM org.openqa.selenium.remote.RemoteWebDriver execute
INFO: Executing: [e36c6b06-ab81-4daf-b99a-1af8cbc138cd, sendKeysToElement {"id":"e9a6a8d3-301f-49a7-85fc-977f35414095","value":["test"]}]
Jan 13, 2012 5:43:30 AM org.openqa.selenium.remote.RemoteWebDriver execute
INFO: Executing: [e36c6b06-ab81-4daf-b99a-1af8cbc138cd, findElement {"using":"name","value":"p"}]
Jan 13, 2012 5:43:33 AM org.openqa.selenium.remote.RemoteWebDriver execute
INFO: Executing: [e36c6b06-ab81-4daf-b99a-1af8cbc138cd, sendKeysToElement {"id":"c9373957-5fcd-4a63-999f-bf54fa1cc9fd","value":["test"]}]
Jan 13, 2012 5:43:40 AM org.openqa.selenium.remote.RemoteWebDriver execute
INFO: Executing: [e36c6b06-ab81-4daf-b99a-1af8cbc138cd, submitElement {"id":"c9373957-5fcd-4a63-999f-bf54fa1cc9fd"}]
Jan 13, 2012 5:43:59 AM org.openqa.selenium.remote.RemoteWebDriver execute
INFO: Executing: [e36c6b06-ab81-4daf-b99a-1af8cbc138cd, switchToWindow {"name":"353b31e2-046e-403f-96da-4f520163d341"}]



However, in 2.20 the output is like this,

Apr 6, 2012 12:17:02 PM java.util.logging.LogManager$RootLogger log
INFO: Logging of firefox driver is enabled
Apr 6, 2012 12:17:02 PM java.util.logging.LogManager$RootLogger log
INFO: Logging of firefox driver is enabled
Tabsv2.conf
Apr 6, 2012 12:17:02 PM org.openqa.selenium.remote.RemoteWebDriver log
FINE: Executing: get
Apr 6, 2012 12:17:02 PM org.openqa.selenium.remote.RemoteWebDriver log
FINE: Executing: getCurrentWindowHandle
Apr 6, 2012 12:17:04 PM org.openqa.selenium.remote.RemoteWebDriver log
FINE: Executing: getCurrentWindowHandle
{339289c1-afc6-4352-8ba5-b8e5f5c9997c}
Apr 6, 2012 12:17:04 PM org.openqa.selenium.remote.RemoteWebDriver log
FINE: Executing: switchToFrame
Apr 6, 2012 12:17:04 PM org.openqa.selenium.remote.RemoteWebDriver log
FINE: Executing: findElement
Apr 6, 2012 12:17:04 PM org.openqa.selenium.remote.RemoteWebDriver log
FINE: Executing: findElement
Apr 6, 2012 12:17:04 PM org.openqa.selenium.remote.RemoteWebDriver log
FINE: Executing: sendKeysToElement
Apr 6, 2012 12:17:04 PM org.openqa.selenium.remote.RemoteWebDriver log
FINE: Executing: findElement
Apr 6, 2012 12:17:04 PM org.openqa.selenium.remote.RemoteWebDriver log
FINE: Executing: sendKeysToElement
Apr 6, 2012 12:17:05 PM org.openqa.selenium.remote.RemoteWebDriver log
FINE: Executing: submitElement
Apr 6, 2012 12:17:05 PM org.openqa.selenium.remote.RemoteWebDriver log
FINE: Executing: switchToWindow
Apr 6, 2012 12:17:05 PM org.openqa.selenium.remote.RemoteWebDriver log
FINE: Executing: get
Apr 6, 2012 12:17:13 PM org.openqa.selenium.remote.RemoteWebDriver log
FINE: Executing: getCurrentWindowHandle
{339289c1-afc6-4352-8ba5-b8e5f5c9997c}

Notice the difference. Earlier, what the value is passed and what is the text to be typed all printed in the logs. Now, it was changed.


Why? Because they implementation is changed. Earlier this code is used to print the logs in RemoteWebDriver.java

try {
      log(sessionId, command.toString(), command, When.BEFORE);
      response = executor.execute(command);
      if (response == null) {
        log(sessionId, command.toString (), command, When.AFTER);
        return null;
      }


Now, it changed to like this,

try {
      log(sessionId, command.getName(), command, When.BEFORE);
      response = executor.execute(command);
      if (response == null) {
        log(sessionId, command.getName(), command, When.AFTER);
        return null;
      }


So, I changed those lines in source, complied and replaced in the jar file Now, the logs look like as in 2.15.0


Happy Testing.

ShareThis

raja's shared items

There was an error in this gadget

My "Testing" Bundle