You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@drill.apache.org by "Sudheesh Katkam (JIRA)" <ji...@apache.org> on 2016/02/09 01:52:18 UTC

[jira] [Created] (DRILL-4377) Sporadic Error Logged for TestPStoreProviders#verifyZkStore

Sudheesh Katkam created DRILL-4377:
--------------------------------------

             Summary: Sporadic Error Logged for TestPStoreProviders#verifyZkStore
                 Key: DRILL-4377
                 URL: https://issues.apache.org/jira/browse/DRILL-4377
             Project: Apache Drill
          Issue Type: Bug
          Components: Tools, Build & Test
            Reporter: Sudheesh Katkam


Although the test does not fail, there is an error logged sporadically:
{code}
> mvn surefire:test -Dtest=TestPStoreProviders#verifyZkStore
[INFO] Scanning for projects...
[INFO]
[INFO] Using the builder org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder with a thread count of 1
[INFO]
[INFO] ------------------------------------------------------------------------
[INFO] Building exec/Java Execution Engine 1.5.0
[INFO] ------------------------------------------------------------------------
[INFO]
[INFO] --- maven-surefire-plugin:2.17:test (default-cli) @ drill-java-exec ---
[INFO] Surefire report directory: /tmp/apache-drill-1.5.0-src/exec/java-exec/target/surefire-reports

-------------------------------------------------------
 T E S T S
-------------------------------------------------------

-------------------------------------------------------
 T E S T S
-------------------------------------------------------
Running org.apache.drill.exec.store.sys.TestPStoreProviders
00:10:06,236 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy]
00:10:06,236 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml]
00:10:06,237 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/tmp/apache-drill-1.5.0-src/exec/java-exec/target/test-classes/logback.xml]
00:10:06,238 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs multiple times on the classpath.
00:10:06,238 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs at [file:/tmp/apache-drill-1.5.0-src/exec/java-exec/target/classes/logback.xml]
00:10:06,238 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs at [file:/tmp/apache-drill-1.5.0-src/exec/java-exec/target/test-classes/logback.xml]
00:10:06,444 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set
00:10:06,446 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [de.huxhorn.lilith.logback.appender.ClassicMultiplexSocketAppender]
00:10:06,470 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [SOCKET]
00:10:06,533 |-INFO in de.huxhorn.lilith.logback.appender.ClassicMultiplexSocketAppender[SOCKET] - Waiting 1s to establish connections.
00:10:07,533 |-INFO in de.huxhorn.lilith.logback.appender.ClassicMultiplexSocketAppender[SOCKET] - Started de.huxhorn.lilith.logback.appender.ClassicMultiplexSocketAppender[SOCKET]
00:10:07,533 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
00:10:07,539 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [STDOUT]
00:10:07,548 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
00:10:07,619 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [org.apache.drill] to false
00:10:07,619 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - org.apache.drill level set to DEBUG
00:10:07,619 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SOCKET] to Logger[org.apache.drill]
00:10:07,621 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [query.logger] to false
00:10:07,621 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - query.logger level set to INFO
00:10:07,621 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SOCKET] to Logger[query.logger]
00:10:07,621 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - ROOT level set to ERROR
00:10:07,621 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [STDOUT] to Logger[ROOT]
00:10:07,621 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration.
00:10:07,622 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@42432e68 - Registering current configuration as safe fallback point

Running org.apache.drill.exec.store.sys.TestPStoreProviders#verifyZkStore
00:10:09.199 [Curator-PathChildrenCache-0] ERROR o.a.c.f.r.cache.PathChildrenCache -
java.lang.IllegalStateException: instance must be started before calling this method
	at com.google.common.base.Preconditions.checkState(Preconditions.java:149) ~[guava-14.0.1.jar:na]
	at org.apache.curator.framework.imps.CuratorFrameworkImpl.getChildren(CuratorFrameworkImpl.java:379) ~[curator-framework-2.7.1.jar:na]
	at org.apache.curator.framework.recipes.cache.PathChildrenCache.refresh(PathChildrenCache.java:502) ~[curator-recipes-2.7.1.jar:na]
	at org.apache.curator.framework.recipes.cache.RefreshOperation.invoke(RefreshOperation.java:35) ~[curator-recipes-2.7.1.jar:na]
	at org.apache.curator.framework.recipes.cache.PathChildrenCache$9.run(PathChildrenCache.java:759) ~[curator-recipes-2.7.1.jar:na]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [na:1.7.0_79]
	at java.util.concurrent.FutureTask.run(FutureTask.java:262) [na:1.7.0_79]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [na:1.7.0_79]
	at java.util.concurrent.FutureTask.run(FutureTask.java:262) [na:1.7.0_79]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_79]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_79]
	at java.lang.Thread.run(Thread.java:745) [na:1.7.0_79]
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 4.411 sec - in org.apache.drill.exec.store.sys.TestPStoreProviders

Results :

Tests run: 1, Failures: 0, Errors: 0, Skipped: 0

[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 8.141 s
[INFO] Finished at: 2016-02-09T00:10:09+00:00
[INFO] Final Memory: 17M/303M
[INFO] ------------------------------------------------------------------------
{code}

For a repro, add this annotation:
{code}
  @Test
  @RepeatTestRule.Repeat(count = 100)
  public void verifyZkStore() throws Exception {
    ...
  }
{code}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)