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.

Sign up for GitHub

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

Jump to bottom

Details of test failures are sometimes too short #144

Closed
yrodiere opened this issue Jan 8, 2024 · 3 comments · Fixed by #145
Closed

Details of test failures are sometimes too short #144

yrodiere opened this issue Jan 8, 2024 · 3 comments · Fixed by #145

Comments

@yrodiere
Copy link
Member

yrodiere commented Jan 8, 2024

There's something wrong with the "details" of test failures generated by the build reporter: sometimes it's (much) shorter than it ought to, skipping all meaningful information

See for example quarkusio/quarkus#37906 (comment) . We get this:

image

Even though the error message is much more detailed in the logs:

2023-12-22T13:58:35.7557569Z [ERROR] Tests run: 9, Failures: 5, Errors: 0, Skipped: 0, Time elapsed: 1.520 s <<< FAILURE! -- in io.quarkus.reactive.oracle.client.NoConfigTest
2023-12-22T13:58:35.7559818Z [ERROR] io.quarkus.reactive.oracle.client.NoConfigTest.injectedBean_default -- Time elapsed: 0.195 s <<< FAILURE!
2023-12-22T13:58:35.7561085Z java.lang.AssertionError: 
2023-12-22T13:58:35.7561431Z 
2023-12-22T13:58:35.7561614Z Expecting throwable message:
2023-12-22T13:58:35.7563109Z   "io.vertx.oracleclient.OracleException: ORA-12261: Cannot connect to database. Syntax error in Easy Connect connection string localhost:1521/.
2023-12-22T13:58:35.7564706Z https://docs.oracle.com/error-help/db/ora-12261/"
2023-12-22T13:58:35.7565354Z to contain:
2023-12-22T13:58:35.7565734Z   "Connection refused"
2023-12-22T13:58:35.7566162Z but did not.
2023-12-22T13:58:35.7566401Z 
2023-12-22T13:58:35.7566596Z Throwable that failed the check:
2023-12-22T13:58:35.7566960Z 
2023-12-22T13:58:35.7568520Z java.util.concurrent.ExecutionException: io.vertx.oracleclient.OracleException: ORA-12261: Cannot connect to database. Syntax error in Easy Connect connection string localhost:1521/.
2023-12-22T13:58:35.7570764Z https://docs.oracle.com/error-help/db/ora-12261/
2023-12-22T13:58:35.7571905Z 	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396)
2023-12-22T13:58:35.7573522Z 	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2096)
2023-12-22T13:58:35.7574832Z 	at org.assertj.core.internal.Futures.assertFailedWithin(Futures.java:118)
2023-12-22T13:58:35.7576468Z 	at org.assertj.core.api.AbstractCompletableFutureAssert.internalFailsWithin(AbstractCompletableFutureAssert.java:625)
2023-12-22T13:58:35.7578590Z 	at org.assertj.core.api.AbstractCompletableFutureAssert.failsWithin(AbstractCompletableFutureAssert.java:586)
2023-12-22T13:58:35.7580447Z 	at io.quarkus.reactive.oracle.client.NoConfigTest.injectedBean_default(NoConfigTest.java:131)
2023-12-22T13:58:35.7582084Z 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2023-12-22T13:58:35.7583831Z 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
2023-12-22T13:58:35.7585630Z 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2023-12-22T13:58:35.7587130Z 	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
2023-12-22T13:58:35.7588186Z 	at io.quarkus.test.QuarkusUnitTest.runExtensionMethod(QuarkusUnitTest.java:500)
2023-12-22T13:58:35.7589509Z 	at io.quarkus.test.QuarkusUnitTest.interceptTestMethod(QuarkusUnitTest.java:414)
2023-12-22T13:58:35.7591380Z 	at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(InterceptingExecutableInvoker.java:103)
2023-12-22T13:58:35.7593707Z 	at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.lambda$invoke$0(InterceptingExecutableInvoker.java:93)
2023-12-22T13:58:35.7596002Z 	at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)
2023-12-22T13:58:35.7598057Z 	at org.junit.jupiter.engine.extension.TimeoutExtension.intercept(TimeoutExtension.java:156)
2023-12-22T13:58:35.7599884Z 	at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestableMethod(TimeoutExtension.java:147)
2023-12-22T13:58:35.7601562Z 	at org.junit.jupiter.engine.extension.TimeoutExtension.interceptTestMethod(TimeoutExtension.java:86)
2023-12-22T13:58:35.7603830Z 	at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker$ReflectiveInterceptorCall.lambda$ofVoidMethod$0(InterceptingExecutableInvoker.java:103)
2023-12-22T13:58:35.7605941Z 	at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.lambda$invoke$0(InterceptingExecutableInvoker.java:93)
2023-12-22T13:58:35.7608316Z 	at org.junit.jupiter.engine.execution.InvocationInterceptorChain$InterceptedInvocation.proceed(InvocationInterceptorChain.java:106)
2023-12-22T13:58:35.7610830Z 	at org.junit.jupiter.engine.execution.InvocationInterceptorChain.proceed(InvocationInterceptorChain.java:64)
2023-12-22T13:58:35.7613907Z 	at org.junit.jupiter.engine.execution.InvocationInterceptorChain.chainAndInvoke(InvocationInterceptorChain.java:45)
2023-12-22T13:58:35.7616249Z 	at org.junit.jupiter.engine.execution.InvocationInterceptorChain.invoke(InvocationInterceptorChain.java:37)
2023-12-22T13:58:35.7624759Z 	at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:92)
2023-12-22T13:58:35.7626839Z 	at org.junit.jupiter.engine.execution.InterceptingExecutableInvoker.invoke(InterceptingExecutableInvoker.java:86)
2023-12-22T13:58:35.7628972Z 	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.lambda$invokeTestMethod$7(TestMethodTestDescriptor.java:218)
2023-12-22T13:58:35.7631000Z 	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
2023-12-22T13:58:35.7633077Z 	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.invokeTestMethod(TestMethodTestDescriptor.java:214)
2023-12-22T13:58:35.7635171Z 	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:139)
2023-12-22T13:58:35.7636977Z 	at org.junit.jupiter.engine.descriptor.TestMethodTestDescriptor.execute(TestMethodTestDescriptor.java:69)
2023-12-22T13:58:35.7638862Z 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:151)
2023-12-22T13:58:35.7641829Z 	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
2023-12-22T13:58:35.7644537Z 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
2023-12-22T13:58:35.7646388Z 	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
2023-12-22T13:58:35.7648606Z 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
2023-12-22T13:58:35.7650621Z 	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
2023-12-22T13:58:35.7652516Z 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
2023-12-22T13:58:35.7654212Z 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
2023-12-22T13:58:35.7655426Z 	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
2023-12-22T13:58:35.7657215Z 	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:41)
2023-12-22T13:58:35.7659400Z 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:155)
2023-12-22T13:58:35.7661315Z 	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
2023-12-22T13:58:35.7663202Z 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
2023-12-22T13:58:35.7664622Z 	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
2023-12-22T13:58:35.7666153Z 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
2023-12-22T13:58:35.7667812Z 	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
2023-12-22T13:58:35.7669654Z 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
2023-12-22T13:58:35.7671458Z 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
2023-12-22T13:58:35.7672759Z 	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
2023-12-22T13:58:35.7674688Z 	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:41)
2023-12-22T13:58:35.7677117Z 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:155)
2023-12-22T13:58:35.7679058Z 	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
2023-12-22T13:58:35.7681034Z 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
2023-12-22T13:58:35.7682417Z 	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
2023-12-22T13:58:35.7683926Z 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
2023-12-22T13:58:35.7687101Z 	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
2023-12-22T13:58:35.7690125Z 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
2023-12-22T13:58:35.7691867Z 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
2023-12-22T13:58:35.7694895Z 	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:35)
2023-12-22T13:58:35.7697424Z 	at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
2023-12-22T13:58:35.7699570Z 	at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:54)
2023-12-22T13:58:35.7701483Z 	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:198)
2023-12-22T13:58:35.7703619Z 	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:169)
2023-12-22T13:58:35.7705526Z 	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:93)
2023-12-22T13:58:35.7707844Z 	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.lambda$execute$0(EngineExecutionOrchestrator.java:58)
2023-12-22T13:58:35.7710084Z 	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.withInterceptedStreams(EngineExecutionOrchestrator.java:141)
2023-12-22T13:58:35.7712074Z 	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:57)
2023-12-22T13:58:35.7714625Z 	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:103)
2023-12-22T13:58:35.7715952Z 	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:85)
2023-12-22T13:58:35.7717354Z 	at org.junit.platform.launcher.core.DelegatingLauncher.execute(DelegatingLauncher.java:47)
2023-12-22T13:58:35.7718809Z 	at org.apache.maven.surefire.junitplatform.LazyLauncher.execute(LazyLauncher.java:56)
2023-12-22T13:58:35.7720386Z 	at org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.execute(JUnitPlatformProvider.java:184)
2023-12-22T13:58:35.7722154Z 	at org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.invokeAllTests(JUnitPlatformProvider.java:148)
2023-12-22T13:58:35.7723949Z 	at org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.invoke(JUnitPlatformProvider.java:122)
2023-12-22T13:58:35.7725515Z 	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:385)
2023-12-22T13:58:35.7726892Z 	at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:162)
2023-12-22T13:58:35.7728067Z 	at org.apache.maven.surefire.booter.ForkedBooter.run(ForkedBooter.java:507)
2023-12-22T13:58:35.7729083Z 	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:495)
2023-12-22T13:58:35.7731412Z Caused by: io.vertx.oracleclient.OracleException: ORA-12261: Cannot connect to database. Syntax error in Easy Connect connection string localhost:1521/.
2023-12-22T13:58:35.7733377Z https://docs.oracle.com/error-help/db/ora-12261/
2023-12-22T13:58:35.7734717Z Caused by: java.sql.SQLException: ORA-12261: Cannot connect to database. Syntax error in Easy Connect connection string localhost:1521/.
2023-12-22T13:58:35.7735950Z https://docs.oracle.com/error-help/db/ora-12261/
2023-12-22T13:58:35.7736867Z 	at oracle.jdbc.driver.T4CConnection.handleLogonNetException(T4CConnection.java:1398)
2023-12-22T13:58:35.7737906Z 	at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:991)
2023-12-22T13:58:35.7738865Z 	at oracle.jdbc.driver.PhysicalConnection.connect(PhysicalConnection.java:1157)
2023-12-22T13:58:35.7739976Z 	at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:104)
2023-12-22T13:58:35.7741005Z 	at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:825)
2023-12-22T13:58:35.7742194Z 	at oracle.jdbc.datasource.impl.OracleDataSource.getPhysicalConnection(OracleDataSource.java:707)
2023-12-22T13:58:35.7743594Z 	at oracle.jdbc.datasource.impl.OracleDataSource.getConnection(OracleDataSource.java:381)
2023-12-22T13:58:35.7744936Z 	at oracle.jdbc.datasource.impl.OracleDataSource.getConnectionInternal(OracleDataSource.java:2206)
2023-12-22T13:58:35.7746402Z 	at oracle.jdbc.datasource.impl.OracleDataSource$1.build(OracleDataSource.java:1915)
2023-12-22T13:58:35.7747559Z 	at oracle.jdbc.datasource.impl.OracleDataSource$1.build(OracleDataSource.java:1849)
2023-12-22T13:58:35.7760596Z 	at io.vertx.oracleclient.impl.OracleConnectionFactory.lambda$connect$0(OracleConnectionFactory.java:75)
2023-12-22T13:58:35.7761952Z 	at io.vertx.oracleclient.impl.Helper$SQLBlockingCodeHandler.handle(Helper.java:306)
2023-12-22T13:58:35.7763081Z 	at io.vertx.oracleclient.impl.Helper$SQLBlockingCodeHandler.handle(Helper.java:298)
2023-12-22T13:58:35.7764154Z 	at io.vertx.core.impl.ContextBase.lambda$executeBlocking$1(ContextBase.java:180)
2023-12-22T13:58:35.7765318Z 	at io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:277)
2023-12-22T13:58:35.7766399Z 	at io.vertx.core.impl.ContextBase.lambda$internalExecuteBlocking$2(ContextBase.java:199)
2023-12-22T13:58:35.7767806Z 	at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:582)
2023-12-22T13:58:35.7768983Z 	at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
2023-12-22T13:58:35.7770245Z 	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)
2023-12-22T13:58:35.7771506Z 	at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
2023-12-22T13:58:35.7773248Z 	at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
2023-12-22T13:58:35.7774525Z 	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
2023-12-22T13:58:35.7775485Z 	at java.base/java.lang.Thread.run(Thread.java:840)
2023-12-22T13:58:35.7777074Z Caused by: oracle.net.ns.NetException: ORA-12261: Cannot connect to database. Syntax error in Easy Connect connection string localhost:1521/.
2023-12-22T13:58:35.7778740Z https://docs.oracle.com/error-help/db/ora-12261/
2023-12-22T13:58:35.7779822Z 	at oracle.net.resolver.HostnameNamingAdapter.resolve(HostnameNamingAdapter.java:156)
2023-12-22T13:58:35.7781096Z 	at oracle.net.resolver.NameResolver.resolveName(NameResolver.java:150)
2023-12-22T13:58:35.7782320Z 	at oracle.net.resolver.AddrResolution.resolveTNSAddress(AddrResolution.java:903)
2023-12-22T13:58:35.7783649Z 	at oracle.net.resolver.AddrResolution.initConnStrategy(AddrResolution.java:632)
2023-12-22T13:58:35.7784839Z 	at oracle.net.resolver.AddrResolution.<init>(AddrResolution.java:447)
2023-12-22T13:58:35.7785802Z 	at oracle.net.ns.NSProtocol.<init>(NSProtocol.java:246)
2023-12-22T13:58:35.7786680Z 	at oracle.net.ns.NSProtocolNIO.<init>(NSProtocolNIO.java:147)
2023-12-22T13:58:35.7787667Z 	at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:911)
2023-12-22T13:58:35.7788460Z 	... 21 more
2023-12-22T13:58:35.7788710Z 
2023-12-22T13:58:35.7789403Z 	at io.quarkus.reactive.oracle.client.NoConfigTest.injectedBean_default(NoConfigTest.java:133)
2023-12-22T13:58:35.7790639Z 	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
2023-12-22T13:58:35.7791759Z 	at io.quarkus.test.QuarkusUnitTest.runExtensionMethod(QuarkusUnitTest.java:500)
2023-12-22T13:58:35.7793057Z 	at io.quarkus.test.QuarkusUnitTest.interceptTestMethod(QuarkusUnitTest.java:414)
2023-12-22T13:58:35.7794197Z 	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
2023-12-22T13:58:35.7795151Z 	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
2023-12-22T13:58:35.7795771Z 
2023-12-22T13:58:35.7796810Z [ERROR] io.quarkus.reactive.oracle.client.NoConfigTest.mutinyPool_default -- Time elapsed: 0.017 s <<< FAILURE!
[...]

Originally posted by @yrodiere in quarkusio/quarkus#37906 (comment)
@yrodiere yrodiere mentioned this issue Jan 8, 2024
Merged
@gsmet
Copy link
Member

gsmet commented Jan 8, 2024

It has always been this way, we keep the first 3 lines as there is a hard limit in the size of the comments on GitHub, which can become very restrictive when you have a lot of failures.

I could try to keep more lines and see how it goes.

FYI, you have the full stacktrace in the annotations at the bottom of https://github.com/quarkusio/quarkus/runs/19900097523#user-content-test-failure-io.quarkus.reactive.oracle.client.noconfigtest-1 (here I'm not hit by the limit).

gsmet added a commit to gsmet/build-reporter that referenced this issue Jan 8, 2024
@gsmet
Keep 8 lines of stacktrace instead of 3
fc9ce1a 
Fixes quarkusio#144
@gsmet gsmet mentioned this issue Jan 8, 2024
Merged
@yrodiere
Copy link
Member Author

yrodiere commented Jan 8, 2024

If you know what the limit is in GitHub, we could come up with some smart-ish way of determining how many lines we keep. I.e. we first build some template:

...
Details:
<<PLACEHOLDER_001>>

...
Details:
<<PLACEHOLDER_002>>

Then we compute the number of chars/line in that template, and depending on that and the limit we determine how many chars/lines we can keep in each details section, and we replace the placeholders with the truncated details.

@gsmet gsmet closed this as completed in #145 Jan 8, 2024
@gsmet
Copy link
Member

gsmet commented Jan 8, 2024

Yeah I have some logic with various options and some degraded options if the comment is too long.

I went with 8 lines, we will see if we end up having no stacktraces in too many cases.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Keep 8 lines of stacktrace instead of 3 gsmet/build-reporter
2 participants
@yrodiere @gsmet