Как определить, откуда поступают прерывания потока Java?

У меня есть среда автоматизации пользовательского интерфейса, которая запускает тесты с помощью TestNG и просматривает страницы с помощью Selenium/WebDriver. Часто страницы, которые я тестирую, делают вызовы AJAX, которые изменяют DOM при возврате. В этих случаях я использую явное ожидание Selenium, чтобы объявить условие DOM, которое я хочу выполнить, прежде чем автоматизация сможет продолжиться (IE: активируется какая-то кнопка).

Внутренний метод Selenium FluentWait.until обрабатывает это, опрашивая DOM для моего ExpectedCondition каждые 500 мс и вызывая Thread.sleep() между этими проверками.

Когда я запускаю два теста подряд в наборе TestNG, это отлично работает для первого теста, но начинает давать сбой с InterruptedException примерно на полпути через каждый последующий тест. Это последовательно. Исключения выглядят так:

Associated Throwable Type: class org.openqa.selenium.WebDriverException Associated Throwable Message: java.lang.InterruptedException: sleep interrupted

Странно то, что здесь нет многопоточности. Я отключил Selenium Grid, BrowserMob Proxy и любой другой фрагмент кода, который мог конфликтовать. Я прочитал оба этих вопроса:

https://stackoverflow.com/questions/24495176/why-is-thread-sleep-being-interrupted - Закрыто из-за недостаточной детализации, но в одном из предложенных ответов говорится, что для отладки следует переопределить метод Thread.interrupt.

Кто прерывает мой поток? - В принятом ответе также говорится, что следует переопределить метод Thread.interrupt для отладка.

Моя проблема с этим решением заключается в том, что размещение точки останова внутри существующего метода Thread.interrupt не обнаруживает никаких вызовов во время прерывания потока. Сюда входят вызовы из всех моих сторонних зависимостей (IE: TestNG и Selenium). То, что вызывает это прерывание потока, кажется внешним по отношению к моему фреймворку.

Я также пытался вызывать Thread.currentThread.isInterrupted() в каждой точке перед вызовом FluentWait.until, и он неизменно возвращает false. Я даже использовал функцию оценки IntelliJ для проверки isInterrupted внутри самого кода Selenium. Этот поток прерывается только после вызова Thread.sleep внутри FluentWait.until.

Я видел, как это происходит на нескольких серверах сборки Windows, а также на моем Macbook, так что это не похоже на конкретную машину.

Некоторое время я думал, что это может быть вызвано тайм-аутом TestNG, но уменьшение тайм-аута TestNG в моем наборе привело к другому поведению, чем эти прерывания.

В настоящее время я работаю над этой проблемой со следующим кодом, который проглатывает исключение и возобновляет явное ожидание:

public static boolean waitForElementStatus(Stuff)
{

  /* snip - setup for ExpectedCondition (change) */

  long startSeconds = new Date().getTime() / 1000;
  long currentSeconds = startSeconds;
  long remainingSeconds = maxElementStatusChangeSeconds;
  WebDriverWait waitForElement = new WebDriverWait(driver, maxElementStatusChangeSeconds);
  boolean changed = false;
  boolean firstWait = true; // If specified time is 0 we still want to check once.
  out:while(firstWait || remainingSeconds > 0)
  {
    firstWait = false;
    Boolean exceptionThrown = false;
    try
    {
      waitForElement.until(change);
    }
    catch(Throwable t)
    {
      exceptionThrown = true;
      if(t.getCause()) != null
      {
        t = t.getCause(); // InterruptedException is wrapped inside a WebDriverException
      }
      if(t.getClass().equals(InterruptedException.class))
      {
        Thread.interrupted(); // clear interrupt status for this thread
        currentSeconds = new Date().getTime() / 1000;
        remainingSeconds = startSeconds + maxElementStatusChangeSeconds - currentSeconds;
        if(remainingSeconds > 0)
        {
          String warning = String.format("Caught unidentified interrupt inside Selenium " +
          "FluentWait.until call.  Swallowing interrupt and repeating call with [%s] seconds " + 
          "remaining.", remainingSeconds);
          CombinedLogger.warn(warning);
          waitForElement = new WebDriverWait(driver, remainingSeconds);
        }
        else
        {
          // If a timeout exception would have been thrown instead of the interruption then
          // we'll allow the WebDriverWait to execute one last time so it can throw the
          // timeout instead.
          waitForElement = new WebDriverWait(driver, 0);
        }
      }
      else if(haltOnFailure) // for any other exception type such as TimeoutException
      {
        CombinedLogger.error(stuff + "...FAILURE(HALTING)", t);
        break out;
      }
      else // for any other exception type such as TimeoutException
      {
        CombinedLogger.info(stuff + "...failure(non-halting)");
        break out;
      }
    }
    if(!exceptionThrown)
    {
      changed = true;
      CombinedLogger.info(stuff + "...success ");
      break out;
    }
  }
  return changed;
}

Этот обходной путь действительно работает, и, к счастью, эти таинственные прерывания после этого возникают только время от времени (они не повторяются), поэтому тесты могут продолжаться. Однако я понимаю, что проглатывать InterruptedException — дурной тон. Если возможно, я хотел бы определить, где и почему происходят эти прерывания, чтобы я мог положить им конец вместо того, чтобы использовать этот хак.

Простое распространение исключений не вариант, поскольку эти тесты должны продолжать работать, а не покорно падать.

Есть ли какие-либо известные утилиты, аргументы JVM или библиотеки, которые я мог бы использовать и которые помогли бы мне отслеживать прерывания потоков Java, вызванные кодом, который я не могу контролировать?

Обновление от 10 декабря 2014 г. Я сделал два дампа потоков. Один непосредственно перед прерыванием, а другой сразу после него. Единственная разница между ними — это номер строки прерванного потока (после прерывания он переходит от блока try к блоку catch). Не уверен, что это говорит мне, но вот данные:

Full thread dump (immediately before interrupt)

"TestNG@1359" prio=5 tid=0xc nid=NA runnable
  java.lang.Thread.State: RUNNABLE
	  at org.openqa.selenium.support.ui.FluentWait.until(FluentWait.java:232)
	  /* snip - company stuff */
	  at sun.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-1)
	  at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	  at java.lang.reflect.Method.invoke(Method.java:606)
	  at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:84)
	  at org.testng.internal.InvokeMethodRunnable.runOne(InvokeMethodRunnable.java:46)
	  at org.testng.internal.InvokeMethodRunnable.run(InvokeMethodRunnable.java:37)
	  at org.testng.internal.MethodInvocationHelper.invokeWithTimeoutWithNoExecutor(MethodInvocationHelper.java:240)
	  at org.testng.internal.MethodInvocationHelper.invokeWithTimeout(MethodInvocationHelper.java:229)
	  at org.testng.internal.Invoker.invokeMethod(Invoker.java:724)
	  at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:901)
	  at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1231)
	  at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:127)
	  at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111)
	  at org.testng.TestRunner.privateRun(TestRunner.java:767)
	  at org.testng.TestRunner.run(TestRunner.java:617)
	  at org.testng.SuiteRunner.runTest(SuiteRunner.java:348)
	  at org.testng.SuiteRunner.access$000(SuiteRunner.java:38)
	  at org.testng.SuiteRunner$SuiteWorker.run(SuiteRunner.java:382)
	  at org.testng.internal.thread.ThreadUtil$2.call(ThreadUtil.java:64)
	  at java.util.concurrent.FutureTask.run(FutureTask.java:262)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	  at java.lang.Thread.run(Thread.java:745)

"main@1" prio=5 tid=0x1 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at sun.misc.Unsafe.park(Unsafe.java:-1)
	  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
	  at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:422)
	  at java.util.concurrent.FutureTask.get(FutureTask.java:199)
	  at java.util.concurrent.AbstractExecutorService.invokeAll(AbstractExecutorService.java:289)
	  at org.testng.internal.thread.ThreadUtil.execute(ThreadUtil.java:72)
	  at org.testng.SuiteRunner.runInParallelTestMode(SuiteRunner.java:367)
	  at org.testng.SuiteRunner.privateRun(SuiteRunner.java:308)
	  at org.testng.SuiteRunner.run(SuiteRunner.java:254)
	  at org.testng.SuiteRunnerWorker.runSuite(SuiteRunnerWorker.java:52)
	  at org.testng.SuiteRunnerWorker.run(SuiteRunnerWorker.java:86)
	  at org.testng.TestNG.runSuitesSequentially(TestNG.java:1224)
	  at org.testng.TestNG.runSuitesLocally(TestNG.java:1149)
	  at org.testng.TestNG.run(TestNG.java:1057)
	  at org.testng.remote.RemoteTestNG.run(RemoteTestNG.java:111)
	  at org.testng.remote.RemoteTestNG.initAndRun(RemoteTestNG.java:204)
	  at org.testng.remote.RemoteTestNG.main(RemoteTestNG.java:175)
	  at org.testng.RemoteTestNGStarter.main(RemoteTestNGStarter.java:125)

"Thread-8@2432" daemon prio=5 tid=0x15 nid=NA runnable
  java.lang.Thread.State: RUNNABLE
	  at java.io.FileInputStream.readBytes(FileInputStream.java:-1)
	  at java.io.FileInputStream.read(FileInputStream.java:272)
	  at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
	  at java.io.BufferedInputStream.read1(BufferedInputStream.java:275)
	  at java.io.BufferedInputStream.read(BufferedInputStream.java:334)
	  - locked <0xe08> (a java.lang.UNIXProcess$ProcessPipeInputStream)
	  at java.io.FilterInputStream.read(FilterInputStream.java:107)
	  at org.apache.commons.exec.StreamPumper.run(StreamPumper.java:105)
	  at java.lang.Thread.run(Thread.java:745)

"Thread-7@2431" daemon prio=5 tid=0x14 nid=NA runnable
  java.lang.Thread.State: RUNNABLE
	  at java.io.FileInputStream.readBytes(FileInputStream.java:-1)
	  at java.io.FileInputStream.read(FileInputStream.java:272)
	  at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
	  at java.io.BufferedInputStream.read1(BufferedInputStream.java:275)
	  at java.io.BufferedInputStream.read(BufferedInputStream.java:334)
	  - locked <0xe09> (a java.lang.UNIXProcess$ProcessPipeInputStream)
	  at java.io.FilterInputStream.read(FilterInputStream.java:107)
	  at org.apache.commons.exec.StreamPumper.run(StreamPumper.java:105)
	  at java.lang.Thread.run(Thread.java:745)

"Thread-6@2424" prio=5 tid=0x13 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at java.lang.Object.wait(Object.java:-1)
	  at java.lang.Object.wait(Object.java:503)
	  at java.lang.UNIXProcess.waitFor(UNIXProcess.java:261)
	  at org.apache.commons.exec.DefaultExecutor.executeInternal(DefaultExecutor.java:347)
	  at org.apache.commons.exec.DefaultExecutor.access$200(DefaultExecutor.java:46)
	  at org.apache.commons.exec.DefaultExecutor$1.run(DefaultExecutor.java:188)

"process reaper@2008" daemon prio=10 tid=0x10 nid=NA runnable
  java.lang.Thread.State: RUNNABLE
	  at java.lang.UNIXProcess.waitForProcessExit(UNIXProcess.java:-1)
	  at java.lang.UNIXProcess.access$500(UNIXProcess.java:54)
	  at java.lang.UNIXProcess$4.run(UNIXProcess.java:225)
	  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
	  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
	  at java.lang.Thread.run(Thread.java:745)

"ReaderThread@645" prio=5 tid=0xb nid=NA runnable
  java.lang.Thread.State: RUNNABLE
	  at java.net.SocketInputStream.socketRead0(SocketInputStream.java:-1)
	  at java.net.SocketInputStream.read(SocketInputStream.java:152)
	  at java.net.SocketInputStream.read(SocketInputStream.java:122)
	  at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:283)
	  at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:325)
	  at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:177)
	  - locked <0xe0b> (a java.io.InputStreamReader)
	  at java.io.InputStreamReader.read(InputStreamReader.java:184)
	  at java.io.BufferedReader.fill(BufferedReader.java:154)
	  at java.io.BufferedReader.readLine(BufferedReader.java:317)
	  at java.io.BufferedReader.readLine(BufferedReader.java:382)
	  at org.testng.remote.strprotocol.BaseMessageSender$ReaderThread.run(BaseMessageSender.java:245)

"Finalizer@2957" daemon prio=8 tid=0x3 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at java.lang.Object.wait(Object.java:-1)
	  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
	  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
	  at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:189)

"Reference Handler@2958" daemon prio=10 tid=0x2 nid=NA waiting
  java.lang.Thread.State: WAITING
	  at java.lang.Object.wait(Object.java:-1)
	  at java.lang.Object.wait(Object.java:503)
	  at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)

"Signal Dispatcher@2956" daemon prio=9 tid=0x4 nid=NA runnable
  java.lang.Thread.State: RUNNABLE

java selenium-webdriver testng

Alex Jansen 10.12.2014 источник

comment

Странно то, что здесь нет многопоточности. Очевидно, что это неправда, поскольку ваш сон прерывается. Ваш первый шаг должен состоять в том, чтобы попытаться изолировать ваш код и воспроизвести сбой с как можно меньшим количеством движущихся частей. Прежде всего, если вы напишите простой метод main(), который напрямую вызывает ваши методы @Test (в обход TestNG), вас все равно будут прерывать? - dimo414 10.12.2014

comment

Это справедливое замечание. Всегда присутствует некоторая степень многопоточности. Выявление этого сбоя, вероятно, займет у меня несколько дней. Я посмотрю, смогу ли я сделать это в ближайшее время. - Alex Jansen 11.12.2014

Ответы (2)

arrow_upward
0
arrow_downward

Из дампа потока мало что можно сделать из того, что его вызвало. Но на самом деле вы не можете слишком полагаться на Thread.sleep(), он может быть прерван по известной/неизвестной причине. В последнем случае причиной может быть ОС.

Thread.sleep() — один из немногих методов, которые серьезно относятся к прерыванию. Поскольку поток не может обработать InterruptedException, пока он находится в спящем режиме, вам необходимо обработать его.

То, что вы делаете прямо сейчас, может быть не обходным путем, а способом в таких случаях, когда мы не можем обойтись без Thread.sleep().

abhati 11.12.2014

comment

Мои варианты были: # 1-это обходной путь (уже на месте). № 2 — Отказаться от назначенных мне задач, чтобы отследить загадочные прерывания без надлежащих инструментов или журналов, чтобы определить, почему они происходят ... Неудивительно, что я выбрал № 1. - Alex Jansen; 21.01.2015

arrow_upward
0
arrow_downward

Немного устарело, но у меня есть аналогичная проблема, и с помощью вашей ранее опубликованной ссылки (https://stackoverflow.com/a/2476246) Я поставил точку останова в методе Thread.interrupt().

Это показывает, что прерывание было сделано методом StoryManager.waitUntilAllDoneOrFailed(), который запускает метод future.cancel() после тайм-аута, установленного для всей истории.

Вся моя установка:

page.getPageObject().withTimeoutOf(convertDuration(duration)).waitFor(by);

где продолжительность около 60 секунд. (минута связана с некоторыми асинхронными вещами)

а также

configuredEmbedder().embedderControls().useStoryTimeouts("30");

И stackTrace:

at java.util.concurrent.FutureTask.cancel(FutureTask.java:174)
      at org.jbehave.core.embedder.StoryManager.waitUntilAllDoneOrFailed(StoryManager.java:184)
      at org.jbehave.core.embedder.StoryManager.performStories(StoryManager.java:121)
      at org.jbehave.core.embedder.StoryManager.runStories(StoryManager.java:107)

и это прерывает более поздний метод Thread.sleep() в ThucydidesFluentWait.doWait() (в основном в нижнем методе экземпляра Sleeper())

Увеличение тайм-аута истории или правильная настройка тайм-аута waitFor(...) по сравнению с тайм-аутом истории решает проблему с моей стороны.

jan 17.01.2017

Как определить, откуда поступают прерывания потока Java?

Ответы (2)

Вопросы по теме