Details
-
Bug
-
Status: Open
-
Major
-
Resolution: Unresolved
-
None
-
None
-
None
Description
Although the test does not fail, there is an error logged sporadically:
> 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] ------------------------------------------------------------------------
For a repro, add this annotation:
@Test @RepeatTestRule.Repeat(count = 100) public void verifyZkStore() throws Exception { ... }