[
https://issues.apache.org/jira/browse/CASSANDRA-20860?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18016258#comment-18016258
]
Dmitry Konstantinov commented on CASSANDRA-20860:
-------------------------------------------------
{quote}I think the reason is that simulator logs the cluster logs based off the
seed, so if we don't know the seed when setting up logging we have a logging
bug.
{quote}
Actually we have 2 property definers:
* org.apache.cassandra.simulator.logging.RunStartDefiner - provides simulation
start time (as currentTime in seconds), has the require check in static block
* org.apache.cassandra.simulator.logging.SeedDefiner - provides seed, it does
have a require check
{quote}Does this actually fail the test, or just breaks the seed separation of
logging? I thought the last time I touched simulator it was just spam and
doesn't fail the test.
{quote}
I think it does not fail the tests but it pollutes logs and maybe (I've not
verified) slow down their execution.
The definers are used in test/conf/logback-simulator.xml
{code:xml}
<define name="run_start"
class="org.apache.cassandra.simulator.logging.RunStartDefiner" scope="system"/>
<define name="run_seed"
class="org.apache.cassandra.simulator.logging.SeedDefiner" scope="system"/>
{code}
to construct log file paths:
{code:java}
<appender name="HISTORYLOG" class="ch.qos.logback.core.FileAppender">
<file>./build/test/logs/simulator/${run_start}-${run_seed}/history.log</file>
{code}
{code:java}
<appender name="INSTANCEFILE" class="ch.qos.logback.core.FileAppender">
<file>./build/test/logs/simulator/${run_start}-${run_seed}/cluster-${cluster_id}/${instance_id}/system.log</file>
{code}
> Failed to instantiate type
> org.apache.cassandra.simulator.logging.RunStartDefiner
> ---------------------------------------------------------------------------------
>
> Key: CASSANDRA-20860
> URL: https://issues.apache.org/jira/browse/CASSANDRA-20860
> Project: Apache Cassandra
> Issue Type: Bug
> Components: Test/fuzz
> Reporter: Dmitry Konstantinov
> Assignee: Dmitry Konstantinov
> Priority: Normal
> Fix For: 5.1
>
> Attachments: ci_log_73_trunk.log
>
>
> org.apache.cassandra.simulator.test.AccordHarrySimulationTest print errors
> like this:
> {code:java}
> 23:42:59 [junit-timeout] 22:42:53,609 |-ERROR in
> ch.qos.logback.core.model.processor.DefaultProcessor@2d140a7 - Failed to
> traverse model define
> ch.qos.logback.core.model.processor.ModelHandlerException:
> ch.qos.logback.core.util.DynamicClassLoadingException: Failed to instantiate
> type org.apache.cassandra.simulator.logging.RunStartDefiner
> 23:42:59 [junit-timeout] at
> ch.qos.logback.core.model.processor.ModelHandlerException:
> ch.qos.logback.core.util.DynamicClassLoadingException: Failed to instantiate
> type org.apache.cassandra.simulator.logging.RunStartDefiner
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.core.model.processor.DefineModelHandler.handle(DefineModelHandler.java:93)
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.core.model.processor.DefaultProcessor.mainTraverse(DefaultProcessor.java:203)
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.core.model.processor.DefaultProcessor.mainTraverse(DefaultProcessor.java:211)
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.core.model.processor.DefaultProcessor.process(DefaultProcessor.java:104)
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.core.joran.GenericXMLConfigurator.processModel(GenericXMLConfigurator.java:222)
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.core.joran.GenericXMLConfigurator.doConfigure(GenericXMLConfigurator.java:178)
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.core.joran.GenericXMLConfigurator.doConfigure(GenericXMLConfigurator.java:123)
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.core.joran.GenericXMLConfigurator.doConfigure(GenericXMLConfigurator.java:66)
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.classic.util.DefaultJoranConfigurator.configureByResource(DefaultJoranConfigurator.java:68)
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.classic.util.DefaultJoranConfigurator.configure(DefaultJoranConfigurator.java:35)
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.classic.util.ContextInitializer.invokeConfigure(ContextInitializer.java:142)
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:101)
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:67)
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.classic.spi.LogbackServiceProvider.initializeLoggerContext(LogbackServiceProvider.java:51)
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.classic.spi.LogbackServiceProvider.initialize(LogbackServiceProvider.java:44)
> 23:42:59 [junit-timeout] at at
> org.slf4j.LoggerFactory.bind(LoggerFactory.java:201)
> 23:42:59 [junit-timeout] at at
> org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:187)
> 23:42:59 [junit-timeout] at at
> org.slf4j.LoggerFactory.getProvider(LoggerFactory.java:511)
> 23:42:59 [junit-timeout] at at
> org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:497)
> 23:42:59 [junit-timeout] at at
> org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:446)
> 23:42:59 [junit-timeout] at at
> org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:472)
> 23:42:59 [junit-timeout] at at
> org.apache.cassandra.simulator.systems.InterceptingGlobalMethods.<clinit>(InterceptingGlobalMethods.java:48)
> 23:42:59 [junit-timeout] at at
> org.apache.cassandra.simulator.test.SimulationTestBase.simulate(SimulationTestBase.java:390)
> 23:42:59 [junit-timeout] at at
> org.apache.cassandra.simulator.test.SimulationTestBase.simulate(SimulationTestBase.java:363)
> 23:42:59 [junit-timeout] at at
> org.apache.cassandra.simulator.test.AccordJournalSimulationTest.simpleRWTest(AccordJournalSimulationTest.java:60)
> 23:42:59 [junit-timeout] at at
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 23:42:59 [junit-timeout] at at
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> 23:42:59 [junit-timeout] at at
> java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 23:42:59 [junit-timeout] at at
> java.base/java.lang.reflect.Method.invoke(Method.java:566)
> 23:42:59 [junit-timeout] at at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
> 23:42:59 [junit-timeout] at at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> 23:42:59 [junit-timeout] at at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
> 23:42:59 [junit-timeout] at at
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
> 23:42:59 [junit-timeout] at at
> org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
> 23:42:59 [junit-timeout] at at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
> 23:42:59 [junit-timeout] at at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
> 23:42:59 [junit-timeout] at at
> org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
> 23:42:59 [junit-timeout] at at
> org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
> 23:42:59 [junit-timeout] at at
> org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
> 23:42:59 [junit-timeout] at at
> org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
> 23:42:59 [junit-timeout] at at
> org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
> 23:42:59 [junit-timeout] at at
> org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
> 23:42:59 [junit-timeout] at at
> org.junit.runners.ParentRunner.run(ParentRunner.java:363)
> 23:42:59 [junit-timeout] at at
> junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:38)
> 23:42:59 [junit-timeout] at at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:534)
> 23:42:59 [junit-timeout] at at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:1196)
> 23:42:59 [junit-timeout] at at
> org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:1041)
> 23:42:59 [junit-timeout] Caused by:
> ch.qos.logback.core.util.DynamicClassLoadingException: Failed to instantiate
> type org.apache.cassandra.simulator.logging.RunStartDefiner
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.core.util.OptionHelper.instantiateByClassNameAndParameter(OptionHelper.java:69)
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.core.util.OptionHelper.instantiateByClassName(OptionHelper.java:44)
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.core.util.OptionHelper.instantiateByClassName(OptionHelper.java:33)
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.core.model.processor.DefineModelHandler.handle(DefineModelHandler.java:87)
> 23:42:59 [junit-timeout] at ... 46 common frames omitted
> 23:42:59 [junit-timeout] Caused by: java.lang.ExceptionInInitializerError
> 23:42:59 [junit-timeout] at at
> java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native
> Method)
> 23:42:59 [junit-timeout] at at
> java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
> 23:42:59 [junit-timeout] at at
> java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
> 23:42:59 [junit-timeout] at at
> java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
> 23:42:59 [junit-timeout] at at
> ch.qos.logback.core.util.OptionHelper.instantiateByClassNameAndParameter(OptionHelper.java:61)
> 23:42:59 [junit-timeout] at ... 49 common frames omitted
> 23:42:59 [junit-timeout] Caused by: java.lang.IllegalStateException
> 23:42:59 [junit-timeout] at at
> accord.utils.Invariants.createIllegalState(Invariants.java:77)
> 23:42:59 [junit-timeout] at at
> accord.utils.Invariants.illegalState(Invariants.java:82)
> 23:42:59 [junit-timeout] at at
> accord.utils.Invariants.illegalState(Invariants.java:92)
> 23:42:59 [junit-timeout] at at
> accord.utils.Invariants.require(Invariants.java:224)
> 23:42:59 [junit-timeout] at at
> org.apache.cassandra.simulator.logging.RunStartDefiner.<clinit>(RunStartDefiner.java:29)
> 23:42:59 [junit-timeout] at ... 54 common frames omitted
> {code}
> If I got correctly it is caused by initializing a logger here:
> org.apache.cassandra.simulator.systems.InterceptingGlobalMethods
> {code}
> private static final Logger logger =
> LoggerFactory.getLogger(InterceptingGlobalMethods.class);
> {code}
> The logger is not actually used, so I suppose we can just remove the line.
> Based on the changes in a similar place in
> https://github.com/apache/cassandra/commit/e6cf2132ab33b2d6e68e79cb2e6d5c3a31103088#diff-d7c7bbcde5f2ce09a2113d707d824661d635ca7fb5dfb0c44cc9ce597e20ed1cR98
> logger usage is not expected during an initialisation of simulation framework.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscr...@cassandra.apache.org
For additional commands, e-mail: commits-h...@cassandra.apache.org
