Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

RATIS-915. Improve output of tests #79

Merged
merged 1 commit into from May 5, 2020

Conversation

adoroszlai
Copy link
Contributor

@adoroszlai adoroszlai commented Apr 30, 2020

What changes were proposed in this pull request?

  1. include stack trace for test failures in results
  2. include thread name in log message format

https://issues.apache.org/jira/browse/RATIS-915

How was this patch tested?

Ran unit tests, verified output files.

Test result

$ cat ratis-test/target/surefire-reports/org.apache.ratis.server.simulation.TestRaftSnapshotWithSimulatedRpc.txt
-------------------------------------------------------------------------------
Test set: org.apache.ratis.server.simulation.TestRaftSnapshotWithSimulatedRpc
-------------------------------------------------------------------------------
Tests run: 2, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 3.911 s <<< FAILURE! - in org.apache.ratis.server.simulation.TestRaftSnapshotWithSimulatedRpc
testBasicInstallSnapshot(org.apache.ratis.server.simulation.TestRaftSnapshotWithSimulatedRpc)  Time elapsed: 2.154 s  <<< FAILURE!
java.lang.AssertionError
	at org.junit.Assert.fail(Assert.java:86)
	at org.junit.Assert.assertTrue(Assert.java:41)
	at org.junit.Assert.assertTrue(Assert.java:52)
	at org.apache.ratis.statemachine.RaftSnapshotBaseTest.verifyTakeSnapshotMetric(RaftSnapshotBaseTest.java:261)
	at org.apache.ratis.statemachine.RaftSnapshotBaseTest.testBasicInstallSnapshot(RaftSnapshotBaseTest.java:240)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
	at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:298)
	at org.junit.internal.runners.statements.FailOnTimeout$CallableStatement.call(FailOnTimeout.java:292)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.lang.Thread.run(Thread.java:748)

Previously:

$ cat ratis-test/target/surefire-reports/org.apache.ratis.server.simulation.TestRaftSnapshotWithSimulatedRpc.txt
-------------------------------------------------------------------------------
Test set: org.apache.ratis.server.simulation.TestRaftSnapshotWithSimulatedRpc
-------------------------------------------------------------------------------
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 4.143 s - in org.apache.ratis.server.simulation.TestRaftSnapshotWithSimulatedRpc
testBasicInstallSnapshot(org.apache.ratis.server.simulation.TestRaftSnapshotWithSimulatedRpc)  Time elapsed: 1.772 s  <<< FAILURE!
java.lang.AssertionError

Test output

$ head ratis-test/target/surefire-reports/org.apache.ratis.server.simulation.TestRaftSnapshotWithSimulatedRpc-output.txt
2020-04-30 13:02:42,679 [main] INFO  util.LogUtils (Log4jUtils.java:setLogLevel(32)) - Set org.apache.ratis.conf.ConfUtils log level to WARN
2020-04-30 13:02:42,681 [main] INFO  util.LogUtils (Log4jUtils.java:setLogLevel(32)) - Set org.apache.ratis.util.FileUtils log level to TRACE
2020-04-30 13:02:42,688 [main] INFO  util.LogUtils (Log4jUtils.java:setLogLevel(32)) - Set org.apache.ratis.server.impl.RaftServerImpl log level to DEBUG
2020-04-30 13:02:42,690 [main] INFO  util.LogUtils (Log4jUtils.java:setLogLevel(32)) - Set org.apache.ratis.server.raftlog.RaftLog log level to DEBUG
2020-04-30 13:02:42,690 [main] INFO  util.LogUtils (Log4jUtils.java:setLogLevel(32)) - Set org.apache.ratis.client.RaftClient log level to DEBUG
2020-04-30 13:02:42,707 [Time-limited test] INFO  simulation.MiniRaftClusterWithSimulatedRpc (ConfUtils.java:logGet(44)) - org.apache.ratis.server.simulation.SimulatedRequestReply.simulateLatencyMs = 150 (default)
2020-04-30 13:02:42,744 [Time-limited test] INFO  ratis.MiniRaftCluster (MiniRaftCluster.java:<init>(253)) - new MiniRaftClusterWithSimulatedRpc with group-97D272C34A83:[s0:0.0.0.0:62382]
2020-04-30 13:02:42,744 [Time-limited test] INFO  ratis.MiniRaftCluster (MiniRaftCluster.java:start(287)) - ..............................................................
2020-04-30 13:02:42,744 [Time-limited test] INFO  ratis.MiniRaftCluster (MiniRaftCluster.java:start(288)) - ...
2020-04-30 13:02:42,744 [Time-limited test] INFO  ratis.MiniRaftCluster (MiniRaftCluster.java:start(289)) - ...     Starting MiniRaftClusterWithSimulatedRpc

Previously:

$ head ratis-test/target/surefire-reports/org.apache.ratis.server.simulation.TestRaftSnapshotWithSimulatedRpc-output.txt
2020-04-30 12:58:32,861 INFO  util.LogUtils (Log4jUtils.java:setLogLevel(32)) - Set org.apache.ratis.conf.ConfUtils log level to WARN
2020-04-30 12:58:32,863 INFO  util.LogUtils (Log4jUtils.java:setLogLevel(32)) - Set org.apache.ratis.util.FileUtils log level to TRACE
2020-04-30 12:58:32,870 INFO  util.LogUtils (Log4jUtils.java:setLogLevel(32)) - Set org.apache.ratis.server.impl.RaftServerImpl log level to DEBUG
2020-04-30 12:58:32,871 INFO  util.LogUtils (Log4jUtils.java:setLogLevel(32)) - Set org.apache.ratis.server.raftlog.RaftLog log level to DEBUG
2020-04-30 12:58:32,872 INFO  util.LogUtils (Log4jUtils.java:setLogLevel(32)) - Set org.apache.ratis.client.RaftClient log level to DEBUG
2020-04-30 12:58:32,888 INFO  simulation.MiniRaftClusterWithSimulatedRpc (ConfUtils.java:logGet(44)) - org.apache.ratis.server.simulation.SimulatedRequestReply.simulateLatencyMs = 150 (default)
2020-04-30 12:58:32,924 INFO  ratis.MiniRaftCluster (MiniRaftCluster.java:<init>(253)) - new MiniRaftClusterWithSimulatedRpc with group-3A4AB4492AF0:[s0:0.0.0.0:62332]
2020-04-30 12:58:32,924 INFO  ratis.MiniRaftCluster (MiniRaftCluster.java:start(287)) - ..............................................................
2020-04-30 12:58:32,924 INFO  ratis.MiniRaftCluster (MiniRaftCluster.java:start(288)) - ...
2020-04-30 12:58:32,924 INFO  ratis.MiniRaftCluster (MiniRaftCluster.java:start(289)) - ...     Starting MiniRaftClusterWithSimulatedRpc

https://github.com/adoroszlai/incubator-ratis/runs/632877948

@runzhiwang
Copy link
Contributor

runzhiwang commented May 5, 2020

LGTM. +1

@bshashikant
Copy link
Contributor

Thanks @runzhiwang for reviewing and @adoroszlai for working on it.

@bshashikant bshashikant merged commit a6d9171 into apache:master May 5, 2020
@adoroszlai adoroszlai deleted the RATIS-915 branch May 5, 2020 07:36
@adoroszlai
Copy link
Contributor Author

Thanks @runzhiwang for the review and @bshashikant for reviewing and merging it.

symious pushed a commit to symious/ratis that referenced this pull request Jan 25, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
3 participants