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)
