gradle / playframework

Gradle Play Support
https://gradle.github.io/playframework/
Apache License 2.0
47 stars 41 forks source link

runPlay task fails when multiple slf4j bindings in classpath #90

Open tnielens opened 5 years ago

tnielens commented 5 years ago

See following stacktrace. The mentioned swagger codegen module is a dependency of a gradle plugin I use to generate swagger model classes.

> Task :myProject:runPlay FAILED
Task ':myProject:runPlay' is not up-to-date because:
  Task has not declared any outputs despite executing actions.
Starting process 'Gradle Play Worker 16'. Working directory: /home/tim/dev/projects/openadr-gate/myProject Command: /usr/lib/jvm/java-8-oracle/bin/java -Duser.variant -cp /home/tim/.gradle/caches/5.2.1/workerMain/gradle-worker.jar worker.org.gradle.process.internal.worker.GradleWorkerMain 'Gradle Play Worker 16'
Successfully started process 'Gradle Play Worker 16'
Listening for transport dt_socket at address: 5005
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/home/tim/.gradle/caches/modules-2/files-2.1/io.swagger/swagger-codegen-cli/2.3.1/ea706b76ec9e1587e9deb7ffb6fdfe6e050cb430/swagger-codegen-cli-2.3.1.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/home/tim/.gradle/wrapper/dists/gradle-5.2.1-all/bviwmvmbexq6idcscbicws5me/gradle-5.2.1/lib/gradle-logging-5.2.1.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [org.slf4j.impl.SimpleLoggerFactory]
java.lang.ExceptionInInitializerError
        at java.io.ObjectStreamClass.hasStaticInitializer(Native Method)
        at java.io.ObjectStreamClass.computeDefaultSUID(ObjectStreamClass.java:1941)
        at java.io.ObjectStreamClass.access$100(ObjectStreamClass.java:79)
        at java.io.ObjectStreamClass$2.run(ObjectStreamClass.java:275)
        at java.io.ObjectStreamClass$2.run(ObjectStreamClass.java:273)
        at java.security.AccessController.doPrivileged(Native Method)
        at java.io.ObjectStreamClass.getSerialVersionUID(ObjectStreamClass.java:272)
        at java.io.ObjectStreamClass.initNonProxy(ObjectStreamClass.java:694)
        at java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1885)
        at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1751)
        at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2042)
        at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1573)
        at java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:2287)
        at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:2211)
        at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2069)
        at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1573)
        at java.io.ObjectInputStream.readObject(ObjectInputStream.java:431)
        at org.gradle.process.internal.worker.child.SystemApplicationClassLoaderWorker.call(SystemApplicationClassLoaderWorker.java:112)
        at org.gradle.process.internal.worker.child.SystemApplicationClassLoaderWorker.call(SystemApplicationClassLoaderWorker.java:68)
        at worker.org.gradle.process.internal.worker.GradleWorkerMain.run(GradleWorkerMain.java:62)
        at worker.org.gradle.process.internal.worker.GradleWorkerMain.main(GradleWorkerMain.java:67)
Caused by: java.lang.ClassCastException: org.slf4j.impl.SimpleLogger cannot be cast to org.gradle.api.logging.Logger
        at org.gradle.api.logging.Logging.getLogger(Logging.java:38)
        at org.gradle.playframework.tools.internal.run.PlayWorkerServer.<clinit>(PlayWorkerServer.java:22)
        ... 21 more
:myProject:runPlay (Thread[Execution worker for ':' Thread 3,5,main]) completed. Took 1.159 secs.

FAILURE: Build failed with an exception.

* What went wrong:
Execution failed for task ':myProject:runPlay'.
> Process 'Gradle Play Worker 16' finished with non-zero exit value 1

* Try:
Run with --debug option to get more log output. Run with --scan to get full insights.

* Exception is:
org.gradle.api.tasks.TaskExecutionException: Execution failed for task ':myProject:runPlay'.
        at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter$2.accept(ExecuteActionsTaskExecuter.java:121)
        at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter$2.accept(ExecuteActionsTaskExecuter.java:117)
        at org.gradle.internal.Try$Failure.ifSuccessfulOrElse(Try.java:184)
        at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter.execute(ExecuteActionsTaskExecuter.java:110)
        at org.gradle.api.internal.tasks.execution.ResolveIncrementalChangesTaskExecuter.execute(ResolveIncrementalChangesTaskExecuter.java:84)
        at org.gradle.api.internal.tasks.execution.ResolveTaskOutputCachingStateExecuter.execute(ResolveTaskOutputCachingStateExecuter.java:91)
        at org.gradle.api.internal.tasks.execution.ResolveBeforeExecutionStateTaskExecuter.execute(ResolveBeforeExecutionStateTaskExecuter.java:74)
        at org.gradle.api.internal.tasks.execution.ValidatingTaskExecuter.execute(ValidatingTaskExecuter.java:58)
        at org.gradle.api.internal.tasks.execution.SkipEmptySourceFilesTaskExecuter.execute(SkipEmptySourceFilesTaskExecuter.java:109)
        at org.gradle.api.internal.tasks.execution.ResolveBeforeExecutionOutputsTaskExecuter.execute(ResolveBeforeExecutionOutputsTaskExecuter.java:67)
        at org.gradle.api.internal.tasks.execution.ResolveAfterPreviousExecutionStateTaskExecuter.execute(ResolveAfterPreviousExecutionStateTaskExecuter.java:46)
        at org.gradle.api.internal.tasks.execution.CleanupStaleOutputsExecuter.execute(CleanupStaleOutputsExecuter.java:93)
        at org.gradle.api.internal.tasks.execution.FinalizePropertiesTaskExecuter.execute(FinalizePropertiesTaskExecuter.java:45)
        at org.gradle.api.internal.tasks.execution.ResolveTaskExecutionModeExecuter.execute(ResolveTaskExecutionModeExecuter.java:94)
        at org.gradle.api.internal.tasks.execution.SkipTaskWithNoActionsExecuter.execute(SkipTaskWithNoActionsExecuter.java:57)
        at org.gradle.api.internal.tasks.execution.SkipOnlyIfTaskExecuter.execute(SkipOnlyIfTaskExecuter.java:56)
        at org.gradle.api.internal.tasks.execution.CatchExceptionTaskExecuter.execute(CatchExceptionTaskExecuter.java:36)
        at org.gradle.api.internal.tasks.execution.EventFiringTaskExecuter$1.executeTask(EventFiringTaskExecuter.java:63)
        at org.gradle.api.internal.tasks.execution.EventFiringTaskExecuter$1.call(EventFiringTaskExecuter.java:49)
        at org.gradle.api.internal.tasks.execution.EventFiringTaskExecuter$1.call(EventFiringTaskExecuter.java:46)
        at org.gradle.internal.operations.DefaultBuildOperationExecutor$CallableBuildOperationWorker.execute(DefaultBuildOperationExecutor.java:416)
        at org.gradle.internal.operations.DefaultBuildOperationExecutor$CallableBuildOperationWorker.execute(DefaultBuildOperationExecutor.java:406)
        at org.gradle.internal.operations.DefaultBuildOperationExecutor$1.execute(DefaultBuildOperationExecutor.java:165)
        at org.gradle.internal.operations.DefaultBuildOperationExecutor.execute(DefaultBuildOperationExecutor.java:250)
        at org.gradle.internal.operations.DefaultBuildOperationExecutor.execute(DefaultBuildOperationExecutor.java:158)
        at org.gradle.internal.operations.DefaultBuildOperationExecutor.call(DefaultBuildOperationExecutor.java:102)
        at org.gradle.internal.operations.DelegatingBuildOperationExecutor.call(DelegatingBuildOperationExecutor.java:36)
        at org.gradle.api.internal.tasks.execution.EventFiringTaskExecuter.execute(EventFiringTaskExecuter.java:46)
        at org.gradle.execution.plan.LocalTaskNodeExecutor.execute(LocalTaskNodeExecutor.java:43)
        at org.gradle.execution.taskgraph.DefaultTaskExecutionGraph$InvokeNodeExecutorsAction.execute(DefaultTaskExecutionGraph.java:355)
        at org.gradle.execution.taskgraph.DefaultTaskExecutionGraph$InvokeNodeExecutorsAction.execute(DefaultTaskExecutionGraph.java:343)
        at org.gradle.execution.taskgraph.DefaultTaskExecutionGraph$BuildOperationAwareExecutionAction.execute(DefaultTaskExecutionGraph.java:336)
        at org.gradle.execution.taskgraph.DefaultTaskExecutionGraph$BuildOperationAwareExecutionAction.execute(DefaultTaskExecutionGraph.java:322)
        at org.gradle.execution.plan.DefaultPlanExecutor$ExecutorWorker$1.execute(DefaultPlanExecutor.java:134)
        at org.gradle.execution.plan.DefaultPlanExecutor$ExecutorWorker$1.execute(DefaultPlanExecutor.java:129)
        at org.gradle.execution.plan.DefaultPlanExecutor$ExecutorWorker.execute(DefaultPlanExecutor.java:202)
        at org.gradle.execution.plan.DefaultPlanExecutor$ExecutorWorker.executeNextNode(DefaultPlanExecutor.java:193)
        at org.gradle.execution.plan.DefaultPlanExecutor$ExecutorWorker.run(DefaultPlanExecutor.java:129)
        at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:63)
        at org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:46)
        at org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:55)
Caused by: org.gradle.process.internal.ExecException: Process 'Gradle Play Worker 16' finished with non-zero exit value 1
        at org.gradle.process.internal.DefaultExecHandle$ExecResultImpl.assertNormalExitValue(DefaultExecHandle.java:396)
        at org.gradle.process.internal.worker.DefaultWorkerProcess.onProcessStop(DefaultWorkerProcess.java:139)
        at org.gradle.process.internal.worker.DefaultWorkerProcess.access$000(DefaultWorkerProcess.java:42)
        at org.gradle.process.internal.worker.DefaultWorkerProcess$1.executionFinished(DefaultWorkerProcess.java:92)
        at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
        at org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
        at org.gradle.internal.event.AbstractBroadcastDispatch.dispatch(AbstractBroadcastDispatch.java:42)
        at org.gradle.internal.event.BroadcastDispatch$SingletonDispatch.dispatch(BroadcastDispatch.java:230)
        at org.gradle.internal.event.BroadcastDispatch$SingletonDispatch.dispatch(BroadcastDispatch.java:149)
        at org.gradle.internal.event.ListenerBroadcast.dispatch(ListenerBroadcast.java:140)
        at org.gradle.internal.event.ListenerBroadcast.dispatch(ListenerBroadcast.java:37)
        at org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
        at com.sun.proxy.$Proxy76.executionFinished(Unknown Source)
        at org.gradle.process.internal.DefaultExecHandle.setEndStateInfo(DefaultExecHandle.java:212)
        at org.gradle.process.internal.DefaultExecHandle.finished(DefaultExecHandle.java:341)
        at org.gradle.process.internal.ExecHandleRunner.completed(ExecHandleRunner.java:109)
        at org.gradle.process.internal.ExecHandleRunner.run(ExecHandleRunner.java:83)
        at org.gradle.internal.operations.CurrentBuildOperationPreservingRunnable.run(CurrentBuildOperationPreservingRunnable.java:42)
        ... 3 more
bmuschko commented 5 years ago

Could you put together a sample project that reproduces the issue?

bmuschko commented 5 years ago

I could reproduce the issue by adding the dependency to the build script's classpath.

buildscript {
    repositories {
        mavenCentral()
    }
    dependencies {
        classpath 'io.swagger.codegen.v3:swagger-codegen-cli:3.0.7'
    }
}

plugins {
    id 'org.gradle.playframework' version '0.4'
}

The dependency swagger-codegen-cli is a fat JAR that bundles other transitive dependencies with the same package name. As a result Gradle cannot properly resolve version conflicts. If you want to include other dependencies in a JAR then those packages should be shaded to avoid conflicts. I suggest you open an issue with the project at https://github.com/swagger-api/swagger-codegen.

Ultimately, I think the worker API lets Gradle core's classpath bleed into the classpath of the plugin. This is the relevant issue: https://github.com/gradle/gradle/issues/3698. So the issue is twofold. I guess you could also get around the issue if swagger-codegen-cli would shade its dependencies.

Generally speaking I don't think you necessarily want to add the dependency to the buildscript's classpath. Instead you could create a custom configuration, assign the swagger-codegen-cli dependency to it and then pass the classpath to the task that runs the code generation e.g. JavaExec.classpath. But I'd really need to see your code and understand what you are trying to achieve.

ymwang1984 commented 5 years ago

@bmuschko Thanks for the analysis. Yes, our case is the same as the swagger plugin (a fat jar on build classpath). We will attempt to do something to get pass it for the moment.

But we are curious, if we fix the issue https://github.com/gradle/gradle/issues/3698 in Gradle 5.4 release, do we need to worry about this problem we see right now?

bmuschko commented 5 years ago

@ymwang1984 I think if you shaded transitive dependencies in your fat JAR with a different package then there's a good likelihood that you will not run into the reported issue. Alternatively (if you do control how the fat JAR is created), you could just publish a version of the dependency that defines its transitive dependencies in its metadata (e.g. pom.xml -> dependencies block) so that you can use Gradle's dependency management capabilities to modify transitives (e.g. exclude or use the same version as Gradle does). Shading can be achieved with the Shadow plugin.

The worker API will still have the issue for exposing Gradle internal dependencies but the risk of facing the issue is decreased. It looks like https://github.com/gradle/gradle/issues/3698 has been moved to 5.5 and won't be addressed with 5.4 so that won't happen soon.

tnielens commented 5 years ago

applying this comment unblocked me

Generally speaking I don't think you necessarily want to add the dependency to the buildscript's classpath. Instead you could create a custom configuration, assign the swagger-codegen-cli dependency to it and then pass the classpath to the task that runs the code generation e.g. JavaExec.classpath. But I'd really need to see your code and understand what you are trying to achieve.

This issue occured while migrating from precedent "software model" version of the plugin. A clearer error message might be helpful.

Thanks for the help

bmuschko commented 5 years ago

The error message would have to be handled by Gradle core. I am going to close this issue for now.

ymwang1984 commented 5 years ago

Thank you @bmuschko

Just curious about the choice to use Worker API for "runPlay". Worker API allows us to run tasks in parallel AFAIK. However, I don't think "runPlay" is designed to run in parallel with other tasks.

bmuschko commented 5 years ago

@ymwang1984 The software model Play plugin uses deep and complex Gradle core-internal infrastructure to execute external tools in a forked JVM process e.g. Twirl or for running the Play application. Using this infrastructure isn't really feasible in an external plugin without risking future breakages as Gradle evolves and releases new versions. The public API equivalent for this functionality is the worker API.

The new Play plugin configures the worker API to wait with executing any additional work until the processing functionality has been completed (see Twirl processing as an example).

ymwang1984 commented 5 years ago

Makes sense. Thank you.