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

NPE in EclipseXmlFormatterStepImpl.java / PREFERENCE_FACTORY is null #489

Closed
epkanol opened this issue Nov 22, 2019 · 5 comments
Closed
Labels

Comments

@epkanol
Copy link

epkanol commented Nov 22, 2019

NPE in EclipseXmlFormatterStepImpl.java at line 64

Saw this on one of our build machines, but could not reproduce locally on a 4-core laptop.
Happened after a retrigger of the build (due to environmental issues). Reproduced twice in a row (retriggering the Jenkins build), and a third time after submitting a new patch.
Only seen it in one repo so far, we have other repos (around 10) where XML formatting works like a charm

Command line used from Jenkins is

gradle --parallel build check -PuniqueSchema=true --info

08:35:06 ------------------------------------------------------------
08:35:06 Gradle 5.6.3
08:35:06 ------------------------------------------------------------
08:35:06 
08:35:06 Build time:   2019-10-18 00:28:36 UTC
08:35:06 Revision:     bd168bbf5d152c479186a897f2cea494b7875d13
08:35:06 
08:35:06 Kotlin:       1.3.41
08:35:06 Groovy:       2.5.4
08:35:06 Ant:          Apache Ant(TM) version 1.9.14 compiled on March 12 2019
08:35:06 JVM:          1.8.0_221 (Oracle Corporation 25.221-b11)
08:35:06 OS:           Linux 3.10.0-1062.el7.x86_64 amd64

Judging from the code (albeit only checked master), PREFERENCE_FACTORY is null, meaning that
the static method setupFramework() either has not been called (yet), or
SpotlessEclipseFramework.setup() returned false for some reason

This is the spotless version:
classpath group: 'com.diffplug.spotless', name: 'spotless-plugin-gradle', version: '3.24.2'

This is the spotless configuration:

  spotless {
        java {
            googleJavaFormat('1.7')
            licenseHeaderFile file("$project.rootProject.projectDir/config/license.java")
        }
        format 'gradle', {
            target '**/*.gradle'
            trimTrailingWhitespace()
            indentWithSpaces(2)
            endWithNewline()
        }
        format 'xml', {
            target fileTree('.') {
                include 'tests/**/*.xml'
                exclude '**/build/**'
            }
            eclipseWtp('xml').configFile("$project.rootProject.projectDir/config/spotless.xml.prefs")
        }
    }

The xml prefs are standard eclipse prefs:

user@host> cat config/spotless.xml.prefs
eclipse.preferences.version=1
indentationChar=space
indentationSize=2
lineWidth=200
user@host>

08:35:28 Step 'eclipse wtp formatters - XML' found problem in 'some-repo/some-file.xml':
08:35:28 null
08:35:28 java.lang.reflect.InvocationTargetException
08:35:28 	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
08:35:28 	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
08:35:28 	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
08:35:28 	at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
08:35:28 	at com.diffplug.spotless.extra.wtp.EclipseWtpFormatterStep.applyWithFile(EclipseWtpFormatterStep.java:121)
08:35:28 	at com.diffplug.spotless.extra.wtp.EclipseWtpFormatterStep.lambda$createBuilder$0(EclipseWtpFormatterStep.java:52)
08:35:28 	at com.diffplug.spotless.FormatterStepImpl$Standard.format(FormatterStepImpl.java:76)
08:35:28 	at com.diffplug.spotless.FormatterStep$Strict.format(FormatterStep.java:76)
08:35:28 	at com.diffplug.spotless.Formatter.compute(Formatter.java:230)
08:35:28 	at com.diffplug.spotless.Formatter.isClean(Formatter.java:167)
08:35:28 	at com.diffplug.gradle.spotless.SpotlessTask.check(SpotlessTask.java:309)
08:35:28 	at com.diffplug.gradle.spotless.SpotlessTask.performAction(SpotlessTask.java:250)
08:35:28 	at sun.reflect.GeneratedMethodAccessor323.invoke(Unknown Source)
08:35:28 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
08:35:28 	at java.lang.reflect.Method.invoke(Method.java:498)
08:35:28 	at org.gradle.internal.reflect.JavaMethod.invoke(JavaMethod.java:103)
08:35:28 	at org.gradle.api.internal.project.taskfactory.IncrementalTaskInputsTaskAction.doExecute(IncrementalTaskInputsTaskAction.java:47)
08:35:28 	at org.gradle.api.internal.project.taskfactory.StandardTaskAction.execute(StandardTaskAction.java:42)
08:35:28 	at org.gradle.api.internal.project.taskfactory.AbstractIncrementalTaskAction.execute(AbstractIncrementalTaskAction.java:25)
08:35:28 	at org.gradle.api.internal.project.taskfactory.StandardTaskAction.execute(StandardTaskAction.java:28)
08:35:28 	at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter$5.run(ExecuteActionsTaskExecuter.java:476)
08:35:28 	at org.gradle.internal.operations.DefaultBuildOperationExecutor$RunnableBuildOperationWorker.execute(DefaultBuildOperationExecutor.java:402)
08:35:28 	at org.gradle.internal.operations.DefaultBuildOperationExecutor$RunnableBuildOperationWorker.execute(DefaultBuildOperationExecutor.java:394)
08:35:28 	at org.gradle.internal.operations.DefaultBuildOperationExecutor$1.execute(DefaultBuildOperationExecutor.java:165)
08:35:28 	at org.gradle.internal.operations.DefaultBuildOperationExecutor.execute(DefaultBuildOperationExecutor.java:250)
08:35:28 	at org.gradle.internal.operations.DefaultBuildOperationExecutor.execute(DefaultBuildOperationExecutor.java:158)
08:35:28 	at org.gradle.internal.operations.DefaultBuildOperationExecutor.run(DefaultBuildOperationExecutor.java:92)
08:35:28 	at org.gradle.internal.operations.DelegatingBuildOperationExecutor.run(DelegatingBuildOperationExecutor.java:31)
08:35:28 	at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter.executeAction(ExecuteActionsTaskExecuter.java:461)
08:35:28 	at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter.executeActions(ExecuteActionsTaskExecuter.java:444)
08:35:28 	at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter.access$200(ExecuteActionsTaskExecuter.java:93)
08:35:28 	at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter$TaskExecution.execute(ExecuteActionsTaskExecuter.java:237)
08:35:28 	at org.gradle.internal.execution.steps.ExecuteStep.lambda$execute$0(ExecuteStep.java:32)
08:35:28 	at java.util.Optional.map(Optional.java:215)
08:35:28 	at org.gradle.internal.execution.steps.ExecuteStep.execute(ExecuteStep.java:32)
08:35:28 	at org.gradle.internal.execution.steps.ExecuteStep.execute(ExecuteStep.java:26)
08:35:28 	at org.gradle.internal.execution.steps.CleanupOutputsStep.execute(CleanupOutputsStep.java:58)
08:35:28 	at org.gradle.internal.execution.steps.CleanupOutputsStep.execute(CleanupOutputsStep.java:35)
08:35:28 	at org.gradle.internal.execution.steps.ResolveInputChangesStep.execute(ResolveInputChangesStep.java:48)
08:35:28 	at org.gradle.internal.execution.steps.ResolveInputChangesStep.execute(ResolveInputChangesStep.java:33)
08:35:28 	at org.gradle.internal.execution.steps.CancelExecutionStep.execute(CancelExecutionStep.java:39)
08:35:28 	at org.gradle.internal.execution.steps.TimeoutStep.executeWithoutTimeout(TimeoutStep.java:73)
08:35:28 	at org.gradle.internal.execution.steps.TimeoutStep.execute(TimeoutStep.java:54)
08:35:28 	at org.gradle.internal.execution.steps.CatchExceptionStep.execute(CatchExceptionStep.java:35)
08:35:28 	at org.gradle.internal.execution.steps.CreateOutputsStep.execute(CreateOutputsStep.java:51)
08:35:28 	at org.gradle.internal.execution.steps.SnapshotOutputsStep.execute(SnapshotOutputsStep.java:45)
08:35:28 	at org.gradle.internal.execution.steps.SnapshotOutputsStep.execute(SnapshotOutputsStep.java:31)
08:35:28 	at org.gradle.internal.execution.steps.CacheStep.executeWithoutCache(CacheStep.java:208)
08:35:28 	at org.gradle.internal.execution.steps.CacheStep.execute(CacheStep.java:70)
08:35:28 	at org.gradle.internal.execution.steps.CacheStep.execute(CacheStep.java:45)
08:35:28 	at org.gradle.internal.execution.steps.BroadcastChangingOutputsStep.execute(BroadcastChangingOutputsStep.java:49)
08:35:28 	at org.gradle.internal.execution.steps.StoreSnapshotsStep.execute(StoreSnapshotsStep.java:43)
08:35:28 	at org.gradle.internal.execution.steps.StoreSnapshotsStep.execute(StoreSnapshotsStep.java:32)
08:35:28 	at org.gradle.internal.execution.steps.RecordOutputsStep.execute(RecordOutputsStep.java:38)
08:35:28 	at org.gradle.internal.execution.steps.RecordOutputsStep.execute(RecordOutputsStep.java:24)
08:35:28 	at org.gradle.internal.execution.steps.SkipUpToDateStep.executeBecause(SkipUpToDateStep.java:96)
08:35:28 	at org.gradle.internal.execution.steps.SkipUpToDateStep.lambda$execute$0(SkipUpToDateStep.java:89)
08:35:28 	at java.util.Optional.map(Optional.java:215)
08:35:28 	at org.gradle.internal.execution.steps.SkipUpToDateStep.execute(SkipUpToDateStep.java:54)
08:35:28 	at org.gradle.internal.execution.steps.SkipUpToDateStep.execute(SkipUpToDateStep.java:38)
08:35:28 	at org.gradle.internal.execution.steps.ResolveChangesStep.execute(ResolveChangesStep.java:76)
08:35:28 	at org.gradle.internal.execution.steps.ResolveChangesStep.execute(ResolveChangesStep.java:37)
08:35:28 	at org.gradle.internal.execution.steps.legacy.MarkSnapshottingInputsFinishedStep.execute(MarkSnapshottingInputsFinishedStep.java:36)
08:35:28 	at org.gradle.internal.execution.steps.legacy.MarkSnapshottingInputsFinishedStep.execute(MarkSnapshottingInputsFinishedStep.java:26)
08:35:28 	at org.gradle.internal.execution.steps.ResolveCachingStateStep.execute(ResolveCachingStateStep.java:90)
08:35:28 	at org.gradle.internal.execution.steps.ResolveCachingStateStep.execute(ResolveCachingStateStep.java:48)
08:35:28 	at org.gradle.internal.execution.steps.CaptureStateBeforeExecutionStep.execute(CaptureStateBeforeExecutionStep.java:69)
08:35:28 	at org.gradle.internal.execution.steps.CaptureStateBeforeExecutionStep.execute(CaptureStateBeforeExecutionStep.java:47)
08:35:28 	at org.gradle.internal.execution.impl.DefaultWorkExecutor.execute(DefaultWorkExecutor.java:33)
08:35:28 	at org.gradle.api.internal.tasks.execution.ExecuteActionsTaskExecuter.execute(ExecuteActionsTaskExecuter.java:140)
08:35:28 	at org.gradle.api.internal.tasks.execution.ValidatingTaskExecuter.execute(ValidatingTaskExecuter.java:62)
08:35:28 	at org.gradle.api.internal.tasks.execution.SkipEmptySourceFilesTaskExecuter.execute(SkipEmptySourceFilesTaskExecuter.java:108)
08:35:28 	at org.gradle.api.internal.tasks.execution.ResolveBeforeExecutionOutputsTaskExecuter.execute(ResolveBeforeExecutionOutputsTaskExecuter.java:67)
08:35:28 	at org.gradle.api.internal.tasks.execution.ResolveAfterPreviousExecutionStateTaskExecuter.execute(ResolveAfterPreviousExecutionStateTaskExecuter.java:46)
08:35:28 	at org.gradle.api.internal.tasks.execution.CleanupStaleOutputsExecuter.execute(CleanupStaleOutputsExecuter.java:94)
08:35:28 	at org.gradle.api.internal.tasks.execution.FinalizePropertiesTaskExecuter.execute(FinalizePropertiesTaskExecuter.java:46)
08:35:28 	at org.gradle.api.internal.tasks.execution.ResolveTaskExecutionModeExecuter.execute(ResolveTaskExecutionModeExecuter.java:95)
08:35:28 	at org.gradle.api.internal.tasks.execution.SkipTaskWithNoActionsExecuter.execute(SkipTaskWithNoActionsExecuter.java:57)
08:35:28 	at org.gradle.api.internal.tasks.execution.SkipOnlyIfTaskExecuter.execute(SkipOnlyIfTaskExecuter.java:56)
08:35:28 	at org.gradle.api.internal.tasks.execution.CatchExceptionTaskExecuter.execute(CatchExceptionTaskExecuter.java:36)
08:35:28 	at org.gradle.api.internal.tasks.execution.EventFiringTaskExecuter$1.executeTask(EventFiringTaskExecuter.java:77)
08:35:28 	at org.gradle.api.internal.tasks.execution.EventFiringTaskExecuter$1.call(EventFiringTaskExecuter.java:55)
08:35:28 	at org.gradle.api.internal.tasks.execution.EventFiringTaskExecuter$1.call(EventFiringTaskExecuter.java:52)
08:35:28 	at org.gradle.internal.operations.DefaultBuildOperationExecutor$CallableBuildOperationWorker.execute(DefaultBuildOperationExecutor.java:416)
08:35:28 	at org.gradle.internal.operations.DefaultBuildOperationExecutor$CallableBuildOperationWorker.execute(DefaultBuildOperationExecutor.java:406)
08:35:28 	at org.gradle.internal.operations.DefaultBuildOperationExecutor$1.execute(DefaultBuildOperationExecutor.java:165)
08:35:28 	at org.gradle.internal.operations.DefaultBuildOperationExecutor.execute(DefaultBuildOperationExecutor.java:250)
08:35:28 	at org.gradle.internal.operations.DefaultBuildOperationExecutor.execute(DefaultBuildOperationExecutor.java:158)
08:35:28 	at org.gradle.internal.operations.DefaultBuildOperationExecutor.call(DefaultBuildOperationExecutor.java:102)
08:35:28 	at org.gradle.internal.operations.DelegatingBuildOperationExecutor.call(DelegatingBuildOperationExecutor.java:36)
08:35:28 	at org.gradle.api.internal.tasks.execution.EventFiringTaskExecuter.execute(EventFiringTaskExecuter.java:52)
08:35:28 	at org.gradle.execution.plan.LocalTaskNodeExecutor.execute(LocalTaskNodeExecutor.java:43)
08:35:28 	at org.gradle.execution.taskgraph.DefaultTaskExecutionGraph$InvokeNodeExecutorsAction.execute(DefaultTaskExecutionGraph.java:355)
08:35:28 	at org.gradle.execution.taskgraph.DefaultTaskExecutionGraph$InvokeNodeExecutorsAction.execute(DefaultTaskExecutionGraph.java:343)
08:35:28 	at org.gradle.execution.taskgraph.DefaultTaskExecutionGraph$BuildOperationAwareExecutionAction.execute(DefaultTaskExecutionGraph.java:336)
08:35:28 	at org.gradle.execution.taskgraph.DefaultTaskExecutionGraph$BuildOperationAwareExecutionAction.execute(DefaultTaskExecutionGraph.java:322)
08:35:28 	at org.gradle.execution.plan.DefaultPlanExecutor$ExecutorWorker$1.execute(DefaultPlanExecutor.java:134)
08:35:28 	at org.gradle.execution.plan.DefaultPlanExecutor$ExecutorWorker$1.execute(DefaultPlanExecutor.java:129)
08:35:28 	at org.gradle.execution.plan.DefaultPlanExecutor$ExecutorWorker.execute(DefaultPlanExecutor.java:202)
08:35:28 	at org.gradle.execution.plan.DefaultPlanExecutor$ExecutorWorker.executeNextNode(DefaultPlanExecutor.java:193)
08:35:28 	at org.gradle.execution.plan.DefaultPlanExecutor$ExecutorWorker.run(DefaultPlanExecutor.java:129)
08:35:28 	at org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:64)
08:35:28 	at org.gradle.internal.concurrent.ManagedExecutorImpl$1.run(ManagedExecutorImpl.java:48)
08:35:28 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
08:35:28 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
08:35:28 	at org.gradle.internal.concurrent.ThreadFactoryImpl$ManagedThreadRunnable.run(ThreadFactoryImpl.java:56)
08:35:28 	at java.lang.Thread.run(Thread.java:748)
08:35:28 Caused by: java.lang.NullPointerException
08:35:28 	at com.diffplug.spotless.extra.eclipse.wtp.EclipseXmlFormatterStepImpl.<init>(EclipseXmlFormatterStepImpl.java:64)
08:35:28 	... 107 more
@nedtwigg nedtwigg added the bug label Nov 22, 2019
@epkanol
Copy link
Author

epkanol commented Nov 22, 2019

Did some more digging into this issue - sharing my thoughts here - please comment if you'd like:

  • The root cause is a race condition, stemming from the fact that the SpotlessEclipseFramework is synchronized, but fails to protect the condition setting the PREFERENCE_FACTORY (line 90 in EclipseXmlFormatterStepImpl)

https://github.com/diffplug/spotless/blob/master/_ext/eclipse-wtp/src/main/java/com/diffplug/spotless/extra/eclipse/wtp/EclipseXmlFormatterStepImpl.java#L70-L90

Rationale:
The only viable reason that PREFERENCE_FACTORY can be null is that the method SpotlessEclipseFramework.setup() returns false for the thread trying to construct the EclipseXmlFormatterStepImpl()
This is because in EclipseXmlFormatterStepImpl, on line 63, the setupFramework(resolveExternalURI) is called, so we know that it has been called before line 64 tries to access the PREFERENCE_FACTORY.

How can SpotlessEclipseFramework.setup() return false, then?

Simply looking in the code reveals the issue at hand:

public synchronized static boolean setup(Consumer<SpotlessEclipseCoreConfig> core, Consumer<SpotlessEclipseServiceConfig> config, Consumer<SpotlessEclipsePluginConfig> plugins) throws BundleException {
if (null != INSTANCE) {
return false;
}

The designers of this class made a singleton-ish like implementation, and indeed protected the method via the synchronized modifier.
The fault lies in the fact that EclipseXmlFormatterStepImpl relies on the return value in order to perform its initialization.

To see this, simply perform the following thought experiment:
Imagine two threads, A and B, both entering the setupFramework() method, which is currently unsynchronized.
One of these threads (say, A) will enter the synchronized method SpotlessEclipseFramework.setup(), and during this time the other thread (B) is non-runnable (waiting for the static synchronized lock in SpotlessEclipseFramework to become available)
Thread A will perform the tasks in SpotlessEclipseFramework (including setting INSTANCE to non-null).
Now imagine that thread A is paused at line 89 (exactly after exiting the synchronized setup method, but before instantiating PREFERENCE_FACTORY on line 90.
This causes thread B to become runnable, and it will enter the setup method as well.
This time, the setup method will return false, as the INSTANCE field is already set. Thus, the if-statement in setupFramework will never be entered, and PREFERENCE_FACTORY will remain null.

Hence, the NPE in the above stacktrace.

The most obvious solution would be to redo the configuration and initialization part (maybe centralizing to a central repository, where other components fetch their config, always) This calls for a redesign of the various components.
A more brittle solution would be to ensure that all methods (in all classes) that rely on the return value from SpotlessEclipseFramework.setup() in order to perform their initialization must be synchronized, or otherwise mutually excluded from relying on the return value simultaneously in several threads.

The problem described in this issue report could, in all likelihood (but I have not tried this in production), be solved by making the setupFramework() method in EclipseXmlFormatterStepImpl synchronized. But this will not solve possible other classes using the SpotlessEclipseFramework.setup() method.

@nedtwigg
Copy link
Member

Wow! Thanks very much for digging in so deeply. @fvgh generally maintains this bit, and I believe he's quite busy at the moment, so it might be a while before he has a chance to dig in. Regardless, we'd be happy to take a PR for this.

Just as an FYI, when you're looking at code in GitHub, you can press y and it will change the URL to link to the permanent hash, rather than the current location of the branch. Then you can click line numbers in the left gutter, and the URL will change to a link to that line or group of lines. More info here.

@epkanol
Copy link
Author

epkanol commented Nov 23, 2019

Thanks for the GitHub trick, @nedtwigg!
I'll see if I can try out the "quick-n-dirty" solution on our build machines on Monday (just adding a synchronized modifier). I'd be happy to share thoughts about redesign of the initialization parts, if @fvgh becomes available, just ping me in this case.
Thanks for unleashing spotless onto the world :-)

@fvgh
Copy link
Member

fvgh commented Nov 25, 2019

@epkanol Thanks for the research. I wanted to refactor this part of the code for quite some time. Once due to the problem you mentioned, but the complete interface was based on initial assumptions that there are dependencies between core, service and plugin configurations which is not the case.
I thought that the problem will not have an effect in real life, so I did not give it a high priority.
Since I was forced to make the interface with some blind spots, I did not restrict the accessibility form the plugin implementation (including synchronization ).
Can you provide and test a workaround for XML, just putting a synchronization around setup call, synchronizing SpotlessEclipseFramework class? I find it more consistent than synchronizing EclipseXmlFormatterStepImpl.

If you are interested, I am of-course also happy about any PR refactoring that part of the framework.

Thanks for your help and sorry for letting you run into the problem in the first place...

epkanol pushed a commit to epkanol/spotless that referenced this issue Nov 26, 2019
epkanol pushed a commit to epkanol/spotless that referenced this issue Nov 26, 2019
The method EclipseXmlFormatterStepImpl used the return value of
SpotlessEclipseFramework.setup() ir order to take decisions whether
or not to initialize.
This introduced a race condition, which is fixed by making the method
synchronized.
Also removed another empty if-statement in GrEclipseFormatterStepImpl
which also called SpotlessEclipseFramework.setup()
epkanol pushed a commit to epkanol/spotless that referenced this issue Nov 26, 2019
The method EclipseXmlFormatterStepImpl used the return value of
SpotlessEclipseFramework.setup() ir order to take decisions whether
or not to initialize.
This introduced a race condition, which is fixed by making the method
synchronized.
Also removed another empty if-statement in GrEclipseFormatterStepImpl
which also called SpotlessEclipseFramework.setup()
nedtwigg added a commit that referenced this issue Nov 28, 2019
Fix NPE in EclipseXmlFormatterStepImpl (#489)
@nedtwigg
Copy link
Member

Published in x.26.1

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants