arteam / dropwizard-nologback

Demo of a Dropwizard app with log4j 2
MIT License
2 stars 0 forks source link

Imports on logback classic are still present and break Eclipse compilation #1

Open jdimeo opened 6 years ago

jdimeo commented 6 years ago

For more context, see https://github.com/dropwizard/dropwizard/pull/2112

When cloning this repo and running mvn test with no changes, there are test failures:

Running com.github.arteam.dropwizard.nologback.ExampleApplicationTest
Tests run: 1, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 0.12 sec <<< FAILURE!
testAppIsWorking(com.github.arteam.dropwizard.nologback.ExampleApplicationTest)  Time elapsed: 0.01 sec  <<< ERROR!
java.lang.RuntimeException: java.lang.reflect.InvocationTargetException
        at io.dropwizard.testing.DropwizardTestSupport.newApplication(DropwizardTestSupport.java:255)
        at io.dropwizard.testing.DropwizardTestSupport.startIfRequired(DropwizardTestSupport.java:192)
        at io.dropwizard.testing.DropwizardTestSupport.before(DropwizardTestSupport.java:141)
        at io.dropwizard.testing.junit.DropwizardAppRule.before(DropwizardAppRule.java:154)
        at org.junit.rules.ExternalResource$1.evaluate(ExternalResource.java:46)
        at org.junit.rules.RunRules.evaluate(RunRules.java:20)
        at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
        at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
        at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
        at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
        at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
        at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
        at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
        at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
        at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
        at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:252)
        at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:141)
        at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:112)
        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.apache.maven.surefire.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:189)
        at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:165)
        at org.apache.maven.surefire.booter.ProviderFactory.invokeProvider(ProviderFactory.java:85)
        at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:115)
        at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:75)
Caused by: java.lang.reflect.InvocationTargetException
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        at io.dropwizard.testing.DropwizardTestSupport.newApplication(DropwizardTestSupport.java:253)
        ... 26 more
Caused by: java.lang.Error: Unresolved compilation problem:
        The type ch.qos.logback.classic.Level cannot be resolved. It is indirectly referenced from required .class files

        at com.github.arteam.dropwizard.nologback.ExampleApplication.<init>(ExampleApplication.java:1)
        ... 31 more

Results :

Tests in error:
  testAppIsWorking(com.github.arteam.dropwizard.nologback.ExampleApplicationTest): java.lang.reflect.InvocationTargetException

Tests run: 1, Failures: 0, Errors: 1, Skipped: 0

Is it possible the specific version of Java I'm running is somehow "smarter" at realizing the class is missing even though it's not actually used or loaded? I imagine you would've experienced similar test failures but I can't figure out what's wrong on my end... thank you for your help and time on this!

java version "1.8.0_131"
Java(TM) SE Runtime Environment (build 1.8.0_131-b11)
Java HotSpot(TM) 64-Bit Server VM (build 25.131-b11, mixed mode)
arteam commented 6 years ago

Thanks! I was able to reproduce the error with the Eclipse Java compiler. I've added a Maven profile for compilation with it: https://github.com/arteam/dropwizard-nologback/commit/fc0a613dc367444a56ac96cbd51964530b2c9273 and got the same result as you. I will think about a fix in Dropwizard 1.2.* for this issue, because right now it seems the framework relies on implementation-specific behavior in the javac compiler.

jdimeo commented 6 years ago

Ahhh.. I failed to clean first before running mvn test, so I understand now! if I compile with standard javac, it works, if I compile with Eclipse (which I realized I can even embed Eclipse-compiled classes in a maven jar if I don't clean before mvn install) I can break it because of Eclipse-specific compilation behavior. Fascinating! I haven't come across this kind of thing before (usually the compiler differences are immaterial as an "end user" of these kinds of frameworks/libs).

jdimeo commented 6 years ago

Would using the fully qualified class name for Level instead of an import at the top of the class be a sufficient work around?

Update: I cloned Dropwizard, removed all classic logback imports at the top of Application and BootstrapLogging and used fully qualified class names, mvn installed Dropwizard 1.2.1-SNAPSHOT locally and pointed this example app to those .jars, and Eclipse still appears to be throwing the error, so that didn't appear to be a valid workaround.

reksomu371 commented 6 years ago

@arteam Download the demo dropwizard-nologback, running in eclipse IDE. Build is failing.

The project was not built since its build path is incomplete. Cannot find the class file for ch.qos.logback.classic.Level. Fix the build path then try building this project The type ch.qos.logback.classic.Level cannot be resolved. It is indirectly referenced from required .class files

reksomu371 commented 6 years ago

The type ch.qos.logback.classic.Level cannot be resolved. It is indirectly referenced from required .class files

arteam commented 6 years ago

Yes, I am aware of that issue. Maybe we can fix it in Dropwizard 2.0.

reksomu371 commented 6 years ago

Thanks @arteam for the update

reksomu371 commented 6 years ago

@arteam @jdimeo I have migrated from maven to gradle project. It's working with eclipse. Also switched to log4j 1.x due to my project req:.

Here is the buld.gradle file apply plugin: 'java'

sourceCompatibility = 1.8

project.ext { dropwizardVersion = '1.3.0' }

repositories { mavenCentral() }

dependencies { compile ("io.dropwizard:dropwizard-core:$dropwizardVersion") { exclude group: 'org.eclipse.jetty.orbit' exclude group:"ch.qos.logback", module:"logback-core"
exclude group:"ch.qos.logback", module:"logback-classic"
exclude group:"ch.qos.logback", module:"logback-access"
exclude group:"org.slf4j", module:"log4j-over-slf4j"
} compile "log4j:log4j:1.2.17" compile "org.slf4j:log4j-over-slf4j:1.7.21" testCompile "io.dropwizard:dropwizard-testing:1.3.0" }

reksomu371 commented 6 years ago

@arteam My logs are still not going to file appender with nologback dependencies exclusion. It only logs one message "2018-06-26/12:39:19.693/PDT INFO [main] [] [org.hibernate.validator.internal.util.Version.(Version.java:30)ogger{0}]: HV000001: Hibernate Validator 5.4.2.Final". Tried to run in debug mode, at runtime it uses slf4j to find the logging framework, in this case log4j and logs the above message, after which it doesn't log any app logs. Enabled log4j debug and here are the details: log4j: Trying to find [log4j.xml] using context classloader sun.misc.Launcher$AppClassLoader@4e25154f. log4j: Using URL [file:/Users/smuniswa/MyProjects/dropwizard-nologback-master1/bin/log4j.xml] for automatic log4j configuration. log4j: Preferred configurator class: org.apache.log4j.xml.DOMConfigurator log4j: System property is :null log4j: Standard DocumentBuilderFactory search succeded. log4j: DocumentBuilderFactory is: com.sun.org.apache.xerces.internal.jaxp.DocumentBuilderFactoryImpl log4j: debug attribute= "null". log4j: Ignoring debug attribute. log4j: reset attribute= "false". log4j: Threshold ="null". log4j: Level value for root is [INFO]. log4j: root level set to INFO log4j: Class name: [org.apache.log4j.RollingFileAppender] log4j: Setting property [append] to [true]. log4j: Setting property [maxFileSize] to [10MB]. log4j: Setting property [maxBackupIndex] to [2]. log4j: Setting property [file] to [example.log]. log4j: Parsing layout of class: "org.apache.log4j.PatternLayout" log4j: Setting property [conversionPattern] to [%d{yyyy-MM-dd/HH:mm:ss.SSS/zzz} %-5p [%t] [%X{requestTrackerId}] [%logger{0}]: %m%n]. log4j: setFile called: example.log, true log4j: setFile ended log4j: Adding appender named [file] to category [root]. log4j: Class name: [org.apache.log4j.ConsoleAppender] log4j: Parsing layout of class: "org.apache.log4j.PatternLayout" log4j: Setting property [conversionPattern] to [%d{yyyy-MM-dd/HH:mm:ss.SSS/zzz} %-5p [%t] [%X{requestTrackerId}] [%logger{0}]: %m%n]. log4j: Adding appender named [console] to category [root]. 2018-06-26/12:52:57.508/PDT INFO [main] [] [org.hibernate.validator.internal.util.Version.(Version.java:30)ogger{0}]: HV000001: Hibernate Validator 5.4.2.Final 12:52:58.164 [main] DEBUG org.eclipse.jetty.util.log - Logging to Logger[org.eclipse.jetty.util.log] via org.eclipse.jetty.util.log.Slf4jLog 12:52:58.168 [main] INFO org.eclipse.jetty.util.log - Logging initialized @1391ms to org.eclipse.jetty.util.log.Slf4jLog 12:52:58.217 [main] DEBUG org.eclipse.jetty.util.DecoratedObjectFactory - Adding Decorator: org.eclipse.jetty.util.DeprecationWarning@74fe5966 12:52:58.221 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - i.d.j.MutableServletContextHandler@963176{/,null,UNAVAILABLE} added {org.eclipse.jetty.servlet.ServletHandler@65004ff6,MANAGED} 12:52:58.222 [main] DEBUG org.eclipse.jetty.util.DecoratedObjectFactory - Adding Decorator: org.eclipse.jetty.util.DeprecationWarning@4d23015c 12:52:58.223 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - i.d.j.MutableServletContextHandler@383f1975{/,null,UNAVAILABLE} added {org.eclipse.jetty.servlet.ServletHandler@441cc260,MANAGED} 12:52:58.235 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - org.eclipse.jetty.servlet.ServletHandler@441cc260 added {tasks@6907b8e==io.dropwizard.servlets.tasks.TaskServlet,jsp=null,order=1,inst=true,AUTO} 12:52:58.237 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - org.eclipse.jetty.servlet.ServletHandler@441cc260 added {[/tasks/*]=>tasks,POJO} 12:52:58.287 [main] INFO io.dropwizard.server.SimpleServerFactory - Registering jersey handler with root path prefix: /application 12:52:58.289 [main] INFO io.dropwizard.server.SimpleServerFactory - Registering admin handler with root path prefix: /admin 12:52:58.289 [main] INFO com.github.arteam.dropwizard.nologback.ExampleApplication - Version: 0.1 12:52:58.289 [main] INFO com.github.arteam.dropwizard.nologback.ExampleApplication - Pros application testing 12:52:58.292 [main] INFO io.dropwizard.server.SimpleServerFactory - Registering jersey handler with root path prefix: /application 12:52:58.292 [main] INFO io.dropwizard.server.SimpleServerFactory - Registering admin handler with root path prefix: /admin 12:52:58.294 [main] INFO io.dropwizard.server.ServerFactory - Starting ExampleApplication

prathamesh13 commented 6 years ago

@arteam so this means Logback is mandatory for dropwizard as of now and we can't switch to something else, right? The documentation has details for specifying external logging. Is this still valid?

AjiSreekumar commented 6 years ago

Getting build path issues while trying to Exclude Logback from the dropwizard-core artifact.

"The type ch.qos.logback.classic.Level cannot be resolved. It is indirectly referenced from required .class files"

Any help is highly appreciated as I would need to use a separate logging framework in my application

trdesilva commented 5 years ago

For anyone else having the same problem as @reksomu371 described above, make sure to look at this project's pom.xml. In addition to excluding the logback dependencies from dropwizard as shown in their documentation, you need to add log4j dependencies. Your application may still run without the correct logging dependencies, but if you're missing anything like I was, you'll just see the one "Hibernate Validator" message come out wherever you've configured your appender to write to.