Merge pull request #958 from selenide/fix-logging-if-listener-fails

#928 Continue working if one of listeners threw an exception

src/main/java/com/codeborne/selenide/impl/Describe.java

@@ -3,7 +3,6 @@
 import com.codeborne.selenide.Driver;
 import com.codeborne.selenide.SelenideElement;
 import org.openqa.selenium.By;
-import org.openqa.selenium.InvalidElementStateException;
 import org.openqa.selenium.NoSuchElementException;
 import org.openqa.selenium.UnsupportedCommandException;
 import org.openqa.selenium.WebDriverException;
@@ -158,8 +157,7 @@ private Describe isSelected(WebElement element) {
       if (element.isSelected()) {
         sb.append(' ').append("selected:true");
       }
-    } catch (UnsupportedOperationException ignore) {
-    } catch (InvalidElementStateException ignore) {
+    } catch (UnsupportedOperationException | WebDriverException ignore) {
     }
     return this;
   }
@@ -169,10 +167,8 @@ private Describe isDisplayed(WebElement element) {
       if (!element.isDisplayed()) {
         sb.append(' ').append("displayed:false");
       }
-    } catch (UnsupportedOperationException e) {
-      sb.append(' ').append("displayed:").append(e);
-    } catch (InvalidElementStateException e) {
-      sb.append(' ').append("displayed:").append(e);
+    } catch (UnsupportedOperationException | WebDriverException e) {
+      sb.append(' ').append("displayed:").append(Cleanup.of.webdriverExceptionMessage(e));
     }
     return this;
   }

src/main/java/com/codeborne/selenide/logevents/SelenideLogger.java

@@ -4,18 +4,22 @@
 import java.util.Collection;
 import java.util.HashMap;
 import java.util.Map;
+import java.util.logging.Level;
+import java.util.logging.Logger;
 
 import static com.codeborne.selenide.logevents.LogEvent.EventStatus.FAIL;
 
 /**
  * Logs Selenide test steps and notifies all registered LogEventListener about it
  */
 public class SelenideLogger {
+  private static final Logger LOG = Logger.getLogger(SelenideLogger.class.getName());
+
   protected static ThreadLocal<Map<String, LogEventListener>> listeners = new ThreadLocal<>();
 
   /**
    * Add a listener (to the current thread).
-   * @param name unique name of this listener (per thread). 
+   * @param name unique name of this listener (per thread).
    *             Can be used later to remove listener using method {@link #removeListener(String)}
    * @param listener event listener
    */
@@ -52,7 +56,12 @@ public static SelenideLog beginStep(String source, String subject) {
 
     SelenideLog log = new SelenideLog(source, subject);
     for (LogEventListener listener : listeners) {
-      listener.beforeEvent(log);
+      try {
+        listener.beforeEvent(log);
+      }
+      catch (RuntimeException e) {
+        LOG.log(Level.SEVERE, "Failed to call listener " + listener, e);
+      }
     }
     return log;
   }
@@ -61,13 +70,18 @@ public static void commitStep(SelenideLog log, Throwable error) {
     log.setError(error);
     commitStep(log, FAIL);
   }
-  
+
   public static void commitStep(SelenideLog log, LogEvent.EventStatus status) {
     log.setStatus(status);
 
     Collection<LogEventListener> listeners = getEventLoggerListeners();
     for (LogEventListener listener : listeners) {
-      listener.afterEvent(log);
+      try {
+        listener.afterEvent(log);
+      }
+      catch (RuntimeException e) {
+        LOG.log(Level.SEVERE, "Failed to call listener " + listener, e);
+      }
     }
   }
 
@@ -89,7 +103,7 @@ public static <T extends LogEventListener> T removeListener(String name) {
     Map<String, LogEventListener> listeners = SelenideLogger.listeners.get();
     return listeners == null ? null : (T) listeners.remove(name);
   }
-  
+
   public static void removeAllListeners() {
     SelenideLogger.listeners.remove();
   }
@@ -98,8 +112,8 @@ public static void removeAllListeners() {
    * If listener with given name is bound (added) to the current thread.
    *
    * @param name unique name of listener added by method {@link #addListener(String, LogEventListener)}
-   * @return true iff method {@link #addListener(String, LogEventListener)} with 
-   *              corresponding name has been called in current thread. 
+   * @return true if method {@link #addListener(String, LogEventListener)} with
+   *              corresponding name has been called in current thread.
    */
   public static boolean hasListener(String name) {
     Map<String, LogEventListener> listeners = SelenideLogger.listeners.get();

src/test/java/com/codeborne/selenide/impl/DescribeTest.java

@@ -9,6 +9,7 @@
 import org.openqa.selenium.NoSuchElementException;
 import org.openqa.selenium.StaleElementReferenceException;
 import org.openqa.selenium.UnsupportedCommandException;
+import org.openqa.selenium.WebDriverException;
 import org.openqa.selenium.WebElement;
 
 import static com.codeborne.selenide.Condition.visible;
@@ -46,23 +47,15 @@ void shortlyForSelenideElementShouldDelegateToOriginalWebElement() {
   @Test
   void describe() {
     Driver driver = mock(Driver.class);
-    SelenideElement selenideElement = mock(SelenideElement.class);
-    when(selenideElement.getTagName()).thenReturn("h1");
-    when(selenideElement.getText()).thenReturn("Hello yo");
-    when(selenideElement.isDisplayed()).thenReturn(true);
-    when(selenideElement.getAttribute("class")).thenReturn("active");
+    SelenideElement selenideElement = element("h1", "class", "active");
 
     assertThat(Describe.describe(driver, selenideElement)).isEqualTo("<h1 class=\"active\">Hello yo</h1>");
   }
 
   @Test
   void describe_appium_NoSuchElementException() {
     Driver driver = mock(Driver.class);
-    SelenideElement selenideElement = mock(SelenideElement.class);
-    when(selenideElement.getTagName()).thenReturn("h1");
-    when(selenideElement.getText()).thenReturn("Hello yo");
-    when(selenideElement.isDisplayed()).thenReturn(true);
-    when(selenideElement.getAttribute("name")).thenReturn("theName");
+    SelenideElement selenideElement = element("h1", "name", "theName");
     when(selenideElement.getAttribute("class")).thenThrow(new NoSuchElementException("Appium throws exception for missing attributes"));
 
     assertThat(Describe.describe(driver, selenideElement)).isEqualTo("<h1 name=\"theName\">Hello yo</h1>");
@@ -71,11 +64,7 @@ void describe_appium_NoSuchElementException() {
   @Test
   void describe_appium_UnsupportedOperationException() {
     Driver driver = mock(Driver.class);
-    SelenideElement selenideElement = mock(SelenideElement.class);
-    when(selenideElement.getTagName()).thenReturn("h1");
-    when(selenideElement.getText()).thenReturn("Hello yo");
-    when(selenideElement.isDisplayed()).thenReturn(true);
-    when(selenideElement.getAttribute("name")).thenReturn("theName");
+    SelenideElement selenideElement = element("h1", "name", "theName");
     when(selenideElement.getAttribute("disabled")).thenThrow(new UnsupportedOperationException(
       "io.appium.uiautomator2.common.exceptions.NoAttributeFoundException: 'disabled' attribute is unknown for the element"));
 
@@ -85,14 +74,57 @@ void describe_appium_UnsupportedOperationException() {
   @Test
   void describe_appium_UnsupportedCommandException() {
     Driver driver = mock(Driver.class);
-    SelenideElement selenideElement = mock(SelenideElement.class);
-    when(selenideElement.getTagName()).thenReturn("h1");
-    when(selenideElement.getText()).thenReturn("Hello yo");
-    when(selenideElement.isDisplayed()).thenReturn(true);
-    when(selenideElement.getAttribute("name")).thenReturn("theName");
+    SelenideElement selenideElement = element("h1", "name", "theName");
     when(selenideElement.getAttribute("disabled")).thenThrow(new UnsupportedCommandException(
       "io.appium.uiautomator2.common.exceptions.NoAttributeFoundException: 'disabled' attribute is unknown for the element"));
 
     assertThat(Describe.describe(driver, selenideElement)).isEqualTo("<h1 name=\"theName\">Hello yo</h1>");
   }
+
+  @Test
+  void describe_appium_isSelected_UnsupportedOperationException() {
+    Driver driver = mock(Driver.class);
+    SelenideElement selenideElement = element("h1", "name", "fname");
+    when(selenideElement.isSelected()).thenThrow(new UnsupportedOperationException("isSelected doesn't work in iOS"));
+
+    assertThat(Describe.describe(driver, selenideElement)).isEqualTo("<h1 name=\"fname\">Hello yo</h1>");
+  }
+
+  @Test
+  void describe_appium_isSelected_WebDriverException() {
+    Driver driver = mock(Driver.class);
+    SelenideElement selenideElement = element("h1", "name", "fname");
+    when(selenideElement.isSelected()).thenThrow(new WebDriverException("isSelected might fail on stolen element"));
+
+    assertThat(Describe.describe(driver, selenideElement)).isEqualTo("<h1 name=\"fname\">Hello yo</h1>");
+  }
+
+  @Test
+  void describe_appium_isDisplayed_UnsupportedOperationException() {
+    Driver driver = mock(Driver.class);
+    SelenideElement selenideElement = element("h1", "name", "fname");
+    when(selenideElement.isDisplayed()).thenThrow(new UnsupportedOperationException("it happens"));
+
+    assertThat(Describe.describe(driver, selenideElement)).isEqualTo(
+      "<h1 name=\"fname\" displayed:java.lang.UnsupportedOperationException: it happens>Hello yo</h1>");
+  }
+
+  @Test
+  void describe_appium_isDisplayed_WebDriverException() {
+    Driver driver = mock(Driver.class);
+    SelenideElement selenideElement = element("h1", "name", "fname");
+    when(selenideElement.isDisplayed()).thenThrow(new WebDriverException("isDisplayed might fail on stolen element"));
+
+    assertThat(Describe.describe(driver, selenideElement)).isEqualTo(
+      "<h1 name=\"fname\" displayed:WebDriverException: isDisplayed might fail on stolen element>Hello yo</h1>");
+  }
+
+  private SelenideElement element(String tagName, String attributeName, String attributeValue) {
+    SelenideElement selenideElement = mock(SelenideElement.class);
+    when(selenideElement.getTagName()).thenReturn(tagName);
+    when(selenideElement.getText()).thenReturn("Hello yo");
+    when(selenideElement.isDisplayed()).thenReturn(true);
+    when(selenideElement.getAttribute(attributeName)).thenReturn(attributeValue);
+    return selenideElement;
+  }
 }

src/test/java/com/codeborne/selenide/logevents/SelenideLoggerTest.java

@@ -1,13 +1,18 @@
 package com.codeborne.selenide.logevents;
 
 import org.assertj.core.api.WithAssertions;
+import org.junit.jupiter.api.AfterEach;
+import org.junit.jupiter.api.BeforeEach;
 import org.junit.jupiter.api.Test;
 import org.mockito.ArgumentCaptor;
 import org.openqa.selenium.By;
 import org.openqa.selenium.WebDriver;
 import org.openqa.selenium.WebElement;
 
+import static com.codeborne.selenide.logevents.LogEvent.EventStatus.FAIL;
 import static com.codeborne.selenide.logevents.LogEvent.EventStatus.PASS;
+import static org.mockito.ArgumentMatchers.any;
+import static org.mockito.Mockito.doThrow;
 import static org.mockito.Mockito.mock;
 import static org.mockito.Mockito.reset;
 import static org.mockito.Mockito.verify;
@@ -17,6 +22,12 @@
 class SelenideLoggerTest implements WithAssertions {
   private WebDriver webdriver = mock(WebDriver.class);
 
+  @BeforeEach
+  @AfterEach
+  void setUp() {
+    SelenideLogger.removeAllListeners();
+  }
+
   @Test
   void convertsJavaMethodNameToHumanReadableClause() {
     assertThat(SelenideLogger.readableMethodName("click"))
@@ -63,9 +74,9 @@ void canAddManyListenersPerThread() {
 
     SelenideLogger.commitStep(SelenideLogger.beginStep("div", "click", null), PASS);
 
-    verifyEvent(listener1);
-    verifyEvent(listener2);
-    verifyEvent(listener3);
+    verifyEvent(listener1, "div", "click()", PASS);
+    verifyEvent(listener2, "div", "click()", PASS);
+    verifyEvent(listener3, "div", "click()", PASS);
 
     verifyNoMoreInteractions(listener1, listener2, listener3);
 
@@ -74,18 +85,44 @@ void canAddManyListenersPerThread() {
     SelenideLogger.removeListener("softAsserts");
 
     SelenideLogger.commitStep(SelenideLogger.beginStep("div", "click", null), PASS);
-    verifyEvent(listener3);
+    verifyEvent(listener3, "div", "click()", PASS);
 
     verifyNoMoreInteractions(listener1, listener2, listener3);
   }
 
-  private void verifyEvent(LogEventListener listener) {
+  @Test
+  void doesNotFail_ifSomeOfListeners_before_throwsException() {
+    LogEventListener listener1 = mock(LogEventListener.class);
+    doThrow(new IllegalStateException("Failed to take screenshot because browser is not opened yet"))
+      .when(listener1).beforeEvent(any());
+    SelenideLogger.addListener("allureListener", listener1);
+
+    SelenideLogger.commitStep(SelenideLogger.beginStep("open", "https://any.url"), FAIL);
+
+    verifyEvent(listener1, "open", "https://any.url", FAIL);
+    verifyNoMoreInteractions(listener1);
+  }
+
+  @Test
+  void doesNotFail_ifSomeOfListeners_after_throwsException() {
+    LogEventListener listener1 = mock(LogEventListener.class);
+    doThrow(new IllegalStateException("Failed to take screenshot because browser is not opened yet"))
+      .when(listener1).afterEvent(any());
+    SelenideLogger.addListener("allureListener", listener1);
+
+    SelenideLogger.commitStep(SelenideLogger.beginStep("open", "https://any.url"), FAIL);
+
+    verifyEvent(listener1, "open", "https://any.url", FAIL);
+    verifyNoMoreInteractions(listener1);
+  }
+
+  private void verifyEvent(LogEventListener listener, String element, String subject, LogEvent.EventStatus status) {
     ArgumentCaptor<LogEvent> event = ArgumentCaptor.forClass(LogEvent.class);
     verify(listener).beforeEvent(event.capture());
     verify(listener).afterEvent(event.capture());
     LogEvent value = event.getValue();
-    assertThat(value.getElement()).isEqualTo("div");
-    assertThat(value.getSubject()).isEqualTo("click()");
-    assertThat(value.getStatus()).isEqualTo(PASS);
+    assertThat(value.getElement()).isEqualTo(element);
+    assertThat(value.getSubject()).isEqualTo(subject);
+    assertThat(value.getStatus()).isEqualTo(status);
   }
 }