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

fix: Verbose logging in test module #1852

Merged
merged 2 commits into from
Sep 5, 2023
Merged

fix: Verbose logging in test module #1852

merged 2 commits into from
Sep 5, 2023

Conversation

Hakky54
Copy link
Contributor

@Hakky54 Hakky54 commented Sep 1, 2023

@joc-a I made an attempt to resolve the verbose logging. Which you also attempted to resolve in #1849 I was not sure whether it is fully resolved. Can you maybe have a look at it? And what do you think of the changes? I just converted the XML configuration file with one that logback is able to understand. Logback is being used internally by logcaptor. Looking forward to your feedback

@Hakky54
Copy link
Contributor Author

Hakky54 commented Sep 1, 2023

I closed the other one #1851 as it might be confusing. This PR is targeted to the main branch whereas the other one was targeted to your own branch.

@Hakky54 Hakky54 changed the title Fixed verbose logging in tests fix: verbose logging in test module Sep 1, 2023
@Hakky54 Hakky54 changed the title fix: verbose logging in test module fix: Verbose logging in test module Sep 1, 2023
Copy link
Collaborator

@joc-a joc-a left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@Hakky54 Thank you for opening a PR. Here is how to test your changes:

  1. Change this line here to this fun <T> getOrNull(expression: Expression<T>): T? = if (hasValue(expression)) get(expression) else null
  2. Run the test testNoWarningsOnLeftJoinRegression
  3. You should see only one warning in the console:

WARN Test worker Exposed:getInternal:57 - Column jointable.dataCol is marked as not null, has default db value, but returns null. Possible have to re-read it from DB.

I tried these steps with your changes (except I named the file logback-test.xml and put it in the test directory) and I see the following:

13:30:26,658 |-INFO in ch.qos.logback.classic.LoggerContext[default] - This is logback-classic version 1.3.5
13:30:26,665 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback-test.xml] at [file:/Users/User/Exposed/exposed-tests/build/resources/test/logback-test.xml]
13:30:26,705 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [CONSOLE]
13:30:26,705 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender]
13:30:26,707 |-INFO in ch.qos.logback.core.model.processor.ImplicitModelHandler - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property
13:30:26,716 |-WARN in ch.qos.logback.classic.pattern.DateConverter@30b6ffe0 - Could not instantiate SimpleDateFormat with pattern ABSOLUTE java.lang.IllegalArgumentException: Unknown pattern letter: U
	at java.lang.IllegalArgumentException: Unknown pattern letter: U
	at 	at java.base/java.time.format.DateTimeFormatterBuilder.parsePattern(DateTimeFormatterBuilder.java:1882)
	at 	at java.base/java.time.format.DateTimeFormatterBuilder.appendPattern(DateTimeFormatterBuilder.java:1772)
	at 	at java.base/java.time.format.DateTimeFormatter.ofPattern(DateTimeFormatter.java:566)
	at 	at ch.qos.logback.core.util.CachingDateFormatter.<init>(CachingDateFormatter.java:57)
	at 	at ch.qos.logback.classic.pattern.DateConverter.start(DateConverter.java:49)
	at 	at ch.qos.logback.core.pattern.ConverterUtil.startConverters(ConverterUtil.java:37)
	at 	at ch.qos.logback.core.pattern.PatternLayoutBase.start(PatternLayoutBase.java:90)
	at 	at ch.qos.logback.classic.encoder.PatternLayoutEncoder.start(PatternLayoutEncoder.java:28)
	at 	at ch.qos.logback.core.model.processor.ImplicitModelHandler.postHandleComplex(ImplicitModelHandler.java:208)
	at 	at ch.qos.logback.core.model.processor.ImplicitModelHandler.postHandle(ImplicitModelHandler.java:186)
	at 	at ch.qos.logback.core.model.processor.DefaultProcessor.secondPhaseTraverse(DefaultProcessor.java:257)
	at 	at ch.qos.logback.core.model.processor.DefaultProcessor.secondPhaseTraverse(DefaultProcessor.java:253)
	at 	at ch.qos.logback.core.model.processor.DefaultProcessor.secondPhaseTraverse(DefaultProcessor.java:253)
	at 	at ch.qos.logback.core.model.processor.DefaultProcessor.traversalLoop(DefaultProcessor.java:90)
	at 	at ch.qos.logback.core.model.processor.DefaultProcessor.process(DefaultProcessor.java:106)
	at 	at ch.qos.logback.core.joran.GenericXMLConfigurator.processModel(GenericXMLConfigurator.java:200)
	at 	at ch.qos.logback.core.joran.GenericXMLConfigurator.doConfigure(GenericXMLConfigurator.java:166)
	at 	at ch.qos.logback.core.joran.GenericXMLConfigurator.doConfigure(GenericXMLConfigurator.java:122)
	at 	at ch.qos.logback.core.joran.GenericXMLConfigurator.doConfigure(GenericXMLConfigurator.java:65)
	at 	at ch.qos.logback.classic.util.DefaultJoranConfigurator.configureByResource(DefaultJoranConfigurator.java:53)
	at 	at ch.qos.logback.classic.util.DefaultJoranConfigurator.configure(DefaultJoranConfigurator.java:34)
	at 	at ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:98)
	at 	at ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:77)
	at 	at ch.qos.logback.classic.spi.LogbackServiceProvider.initializeLoggerContext(LogbackServiceProvider.java:50)
	at 	at ch.qos.logback.classic.spi.LogbackServiceProvider.initialize(LogbackServiceProvider.java:41)
	at 	at org.slf4j.LoggerFactory.bind(LoggerFactory.java:183)
	at 	at org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:170)
	at 	at org.slf4j.LoggerFactory.getProvider(LoggerFactory.java:455)
	at 	at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:441)
	at 	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:390)
	at 	at org.jetbrains.exposed.sql.SQLLogKt.<clinit>(SQLLog.kt:14)
	at 	at org.jetbrains.exposed.sql.tests.shared.dml.JoinTests.testNoWarningsOnLeftJoinRegression(JoinTests.kt:196)
	at 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at 	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at 	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:59)
	at 	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
	at 	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:56)
	at 	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
	at 	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
	at 	at org.junit.runners.BlockJUnit4ClassRunner$1.evaluate(BlockJUnit4ClassRunner.java:100)
	at 	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:366)
	at 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
	at 	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
	at 	at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
	at 	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
	at 	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
	at 	at org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
	at 	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
	at 	at org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
	at 	at org.junit.runners.ParentRunner.run(ParentRunner.java:413)
	at 	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.runTestClass(JUnitTestClassExecutor.java:110)
	at 	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.execute(JUnitTestClassExecutor.java:58)
	at 	at org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecutor.execute(JUnitTestClassExecutor.java:38)
	at 	at org.gradle.api.internal.tasks.testing.junit.AbstractJUnitTestClassProcessor.processTestClass(AbstractJUnitTestClassProcessor.java:62)
	at 	at org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:51)
	at 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at 	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at 	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:36)
	at 	at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
	at 	at org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:33)
	at 	at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:94)
	at 	at jdk.proxy1/jdk.proxy1.$Proxy2.processTestClass(Unknown Source)
	at 	at org.gradle.api.internal.tasks.testing.worker.TestWorker$2.run(TestWorker.java:176)
	at 	at org.gradle.api.internal.tasks.testing.worker.TestWorker.executeAndMaintainThreadName(TestWorker.java:129)
	at 	at org.gradle.api.internal.tasks.testing.worker.TestWorker.execute(TestWorker.java:100)
	at 	at org.gradle.api.internal.tasks.testing.worker.TestWorker.execute(TestWorker.java:60)
	at 	at org.gradle.process.internal.worker.child.ActionExecutionWorker.execute(ActionExecutionWorker.java:56)
	at 	at org.gradle.process.internal.worker.child.SystemApplicationClassLoaderWorker.call(SystemApplicationClassLoaderWorker.java:133)
	at 	at org.gradle.process.internal.worker.child.SystemApplicationClassLoaderWorker.call(SystemApplicationClassLoaderWorker.java:71)
	at 	at worker.org.gradle.process.internal.worker.GradleWorkerMain.run(GradleWorkerMain.java:69)
	at 	at worker.org.gradle.process.internal.worker.GradleWorkerMain.main(GradleWorkerMain.java:74)
13:30:26,716 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - Processing appender named [ASYNC]
13:30:26,716 |-INFO in ch.qos.logback.core.model.processor.AppenderModelHandler - About to instantiate appender of type [ch.qos.logback.classic.AsyncAppender]
13:30:26,716 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [CONSOLE] to ch.qos.logback.classic.AsyncAppender[ASYNC]
13:30:26,716 |-INFO in ch.qos.logback.classic.AsyncAppender[ASYNC] - Attaching appender named [CONSOLE] to AsyncAppender.
13:30:26,716 |-INFO in ch.qos.logback.classic.AsyncAppender[ASYNC] - Setting discardingThreshold to 51
13:30:26,716 |-INFO in ch.qos.logback.classic.model.processor.RootLoggerModelHandler - Setting level of ROOT logger to INFO
13:30:26,716 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [ASYNC] to Logger[ROOT]
13:30:26,717 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting level of logger [Exposed] to INFO
13:30:26,717 |-INFO in ch.qos.logback.classic.model.processor.LoggerModelHandler - Setting additivity of logger [Exposed] to false
13:30:26,717 |-INFO in ch.qos.logback.core.model.processor.AppenderRefModelHandler - Attaching appender named [ASYNC] to Logger[Exposed]
13:30:26,717 |-INFO in ch.qos.logback.core.model.processor.DefaultProcessor@24c22fe - End of configuration.
13:30:26,717 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@93081b6 - Registering current configuration as safe fallback point

How can we change that to behave the same as described in Step 3?

@Hakky54
Copy link
Contributor Author

Hakky54 commented Sep 4, 2023

@joc-a The issue was related to the pattern of the encoder, I adjusted it to make it compatible with logback.
I have pushed my latest change. I am getting the same warn message when I adjust the code as you mentioned.

Can you give a try on your side with the latest code changes?

@Hakky54 Hakky54 requested a review from joc-a September 5, 2023 10:25
Copy link
Collaborator

@joc-a joc-a left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Tried this and it works as expected. Thank you!

Just left a comment for consistency with the existing log4j2.xml

exposed-tests/src/test/resources/logback-test.xml Outdated Show resolved Hide resolved
exposed-tests/src/test/resources/logback-test.xml Outdated Show resolved Hide resolved
@Hakky54
Copy link
Contributor Author

Hakky54 commented Sep 5, 2023

Awesome, great to hear that the PR does the job. I have used Exposed library in the past and it is nice to see that your team is using LogCaptor. I am happy to contribute back to you guys in this way. Feel free to ping me if you get stuck or need any help

@joc-a joc-a merged commit a0ab662 into JetBrains:main Sep 5, 2023
3 checks passed
saral pushed a commit to saral/Exposed that referenced this pull request Oct 3, 2023
* Added logback configuratio

* Reverse order for consistency with existing log4j2.xml

---------

Co-authored-by: Jocelyne <38375996+joc-a@users.noreply.github.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants