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

Reduce reflection in CpsFlowExecution #627

Merged
merged 1 commit into from Dec 5, 2022
Merged

Conversation

basil
Copy link
Member

@basil basil commented Nov 13, 2022

Jenkins core currently specifies --add-opens java.base/java.io=ALL-UNNAMED, which is technical debt in the sense that it enables deprecated behavior. This is only needed for workflow-cps's cleanUpObjectStreamClassCaches method, and that method is in turn only needed for old JVMs that do not have the fix for JDK-8277072. This PR makes the reflection-based logic conditional on running on these older JVMs, so that when running on a newer JVM the illegal reflective access is not attempted. When this PR is widely adopted, we can remove the --add-opens java.base/java.io=ALL-UNNAMED directive from Jenkins core and clean up this technical debt.

To test this change I removed --add-opens java.base/java.io=ALL-UNNAMED and verified that this exception was logged even when running on Java 11.0.17:

java.lang.reflect.InaccessibleObjectException: Unable to make field static final java.io.ClassCache java.io.ObjectStreamClass$Caches.localDescs accessible: module java.base does not "opens java.io" to unnamed module @2cb2b9bd
        at java.base/java.lang.reflect.AccessibleObject.throwInaccessibleObjectException(AccessibleObject.java:387)
        at java.base/java.lang.reflect.AccessibleObject.checkCanSetAccessible(AccessibleObject.java:363)
        at java.base/java.lang.reflect.AccessibleObject.checkCanSetAccessible(AccessibleObject.java:311)
        at java.base/java.lang.reflect.Field.checkCanSetAccessible(Field.java:180)
        at java.base/java.lang.reflect.Field.setAccessible(Field.java:174)
        at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.cleanUpObjectStreamClassCaches(CpsFlowExecution.java:1489)
        at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.cleanUpLoader(CpsFlowExecution.java:1346)
        at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.cleanUpHeap(CpsFlowExecution.java:1311)
        at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup.run(CpsThreadGroup.java:464)
        at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup.access$400(CpsThreadGroup.java:95)
        at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$2.call(CpsThreadGroup.java:330)
        at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$2.call(CpsThreadGroup.java:294)
        at org.jenkinsci.plugins.workflow.cps.CpsVmExecutorService$2.call(CpsVmExecutorService.java:67)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
        at hudson.remoting.SingleLaneExecutorService$1.run(SingleLaneExecutorService.java:139)
        at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:30)
        at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:70)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:577)
        at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
        at java.base/java.lang.Thread.run(Thread.java:1589)

With this PR the exception is no longer logged. If accepted I will make a similar PR for the copypasta of this code in script-security.

@basil basil requested a review from a team as a code owner November 13, 2022 19:07
@jglick
Copy link
Member

jglick commented Nov 14, 2022

Or just clean up now. #600 (comment) maybe Jenkins core should somehow warn you when you are running on a Java version known to be outdated, especially if a release of core or any plugin you are using is newer than the release of Java superseding the one you are on.

@basil
Copy link
Member Author

basil commented Nov 14, 2022

Or just clean up now

Not interested

@basil
Copy link
Member Author

basil commented Dec 5, 2022

Unlike many of my other cleanup PRs, the timing of the merge and release of this PR is relevant: the longer it takes for this PR to be widely adopted, the longer we are forced to maintain the technical debt of the --add-opens java.base/java.io=ALL-UNNAMED directive in Jenkins core.

@jglick
Copy link
Member

jglick commented Dec 5, 2022

Sorry, was hoping a more active maintainer might merge, but I guess not!

@jglick jglick merged commit 4bd9b8c into jenkinsci:master Dec 5, 2022
@basil basil deleted the reflection branch December 5, 2022 18:04
@jimklimov
Copy link

jimklimov commented Dec 15, 2022

Cheers, somehow this broke our shared library (with controller running on JDK 17.0.5 so now not doing that magic code the PR fenced). Sample code which breaks was a debug print ending up in an each{} processing - I don't know yet if this is one case to fix for our setup or there would be dozens of similar issues - each{} is extensively used as it was touted to be "mostly-CPS-safe" compared to for(); any{}/all{} and similar constructs also happen in the shared library codebase but much less often...

This cropped up after updates to workflow-cps:3565.v4b_d9b_8c29a_b_3 and workflow-cps:3581.v2b_e4c99c76ed ; not sure if similar fix in script-security:1228.vd93135a_2fb_25 impacted this use-case. Reverting to workflow-cps:3536.vb_8a_6628079d5 and script-security:1218.v39ca_7f7ed0a_c did hot-fix the issue in the field. By changeset description this reflection-reduction seemed most relevant, but maybe the issue was root-caused in some other bugfix.

A trimmed-down version of this looks like this:

  • The call which worked for years looks benign:
	helper.printlnDebugTrace ("lock() resource: " +
				"Considering MANAGE_LOCK logic:",
				"current name: '${LOCK_NAME}'",
				"obj: ${LOCK_OBJ}",
				"labels: '${LOCK_LABEL}'",
				"HONOUR_LOCK_OWNER: '${HONOUR_LOCK_OWNER}'",
				"MANAGE_LOCK_OWNER: '${MANAGE_LOCK_OWNER}'",
				LRtoString()
				)
  • It refers to a global helper class method with an each inside:
	static def printlnDebugTrace(Object... msg) {
		if (helper.shouldDebugTrace()) {
			return helper.script?.println(prefixMultiline('[DEBUG-TRACE]', msg))
		}
		return null
	}

	static String prefixMultiline(String tag, Object... msg) {
		if (msg?.size() > 0) {
			String s = ""
			msg.each {
				if (s != "") s += '\n'
				s += "${tag}: ${it?.toString()}"
			}
			return s
		}
		return null
	}
  • In "our" code, the stack trace fails at msg.each line's number (893 below) which I separated by a blank from "core code" which now behaves differently than a month ago and errors out:
java.lang.NullPointerException
	at java.base/java.util.Objects.requireNonNull(Objects.java:208)
	at java.base/java.util.ImmutableCollections.listFromArray(ImmutableCollections.java:190)
	at java.base/java.util.List.of(List.java:1047)
	at org.jenkinsci.plugins.workflow.cps.persistence.IteratorHack.iterator(IteratorHack.java:105)
	at jdk.internal.reflect.GeneratedMethodAccessor364.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at org.codehaus.groovy.runtime.metaclass.ReflectionMetaMethod.invoke(ReflectionMetaMethod.java:54)
	at org.codehaus.groovy.runtime.metaclass.NewInstanceMetaMethod.invoke(NewInstanceMetaMethod.java:56)
	at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:325)
	at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1225)
	at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1034)
	at org.codehaus.groovy.runtime.InvokerHelper.invokePojoMethod(InvokerHelper.java:935)
	at org.codehaus.groovy.runtime.InvokerHelper.invokeMethod(InvokerHelper.java:926)
	at org.codehaus.groovy.runtime.InvokerHelper.asIterator(InvokerHelper.java:595)
	at org.codehaus.groovy.runtime.InvokerHelper$asIterator.call(Unknown Source)
	at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:47)
	at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:116)
	at com.cloudbees.groovy.cps.sandbox.DefaultInvoker.methodCall(DefaultInvoker.java:20)
	at com.cloudbees.groovy.cps.CpsDefaultGroovyMethods.each(CpsDefaultGroovyMethods:1980)

	at com.internaldomain.ci.helper.prefixMultiline(helper.groovy:893)
	at com.internaldomain.ci.helper.printlnDebugTrace(helper.groovy:930)
	at com.internaldomain.ci.SUTLockableItem.lock(SUTLockableItem.groovy:1304)
	at com.internaldomain.ci.SUTLockableVM.createClone(SUTLockableVM.groovy:333)
	at WorkflowScript.run(WorkflowScript:670)
	at ___cps.transform___(Native Method)

	at com.cloudbees.groovy.cps.impl.ContinuationGroup.methodCall(ContinuationGroup.java:90)
	at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.dispatchOrArg(FunctionCallBlock.java:116)
	at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.fixArg(FunctionCallBlock.java:85)
	at jdk.internal.reflect.GeneratedMethodAccessor312.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at com.cloudbees.groovy.cps.impl.ContinuationPtr$ContinuationImpl.receive(ContinuationPtr.java:72)
	at com.cloudbees.groovy.cps.impl.LocalVariableBlock$LocalVariable.get(LocalVariableBlock.java:39)
	at com.cloudbees.groovy.cps.LValueBlock$GetAdapter.receive(LValueBlock.java:30)
	at com.cloudbees.groovy.cps.impl.LocalVariableBlock.evalLValue(LocalVariableBlock.java:28)
	at com.cloudbees.groovy.cps.LValueBlock$BlockImpl.eval(LValueBlock.java:55)
	at com.cloudbees.groovy.cps.LValueBlock.eval(LValueBlock.java:16)
	at com.cloudbees.groovy.cps.Next.step(Next.java:83)
	at com.cloudbees.groovy.cps.Continuable$1.call(Continuable.java:152)
	at com.cloudbees.groovy.cps.Continuable$1.call(Continuable.java:146)
	at org.codehaus.groovy.runtime.GroovyCategorySupport$ThreadCategoryInfo.use(GroovyCategorySupport.java:136)
	at org.codehaus.groovy.runtime.GroovyCategorySupport.use(GroovyCategorySupport.java:275)
	at com.cloudbees.groovy.cps.Continuable.run0(Continuable.java:146)
	at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.access$001(SandboxContinuable.java:18)
	at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.run0(SandboxContinuable.java:51)
	at org.jenkinsci.plugins.workflow.cps.CpsThread.runNextChunk(CpsThread.java:187)
	at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup.run(CpsThreadGroup.java:420)
	at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$2.call(CpsThreadGroup.java:330)
	at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$2.call(CpsThreadGroup.java:294)
	at org.jenkinsci.plugins.workflow.cps.CpsVmExecutorService$2.call(CpsVmExecutorService.java:67)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at hudson.remoting.SingleLaneExecutorService$1.run(SingleLaneExecutorService.java:139)
	at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:30)
	at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:70)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:833)
Finished: FAILURE

UPDATE: Looking at those other contemporary PRs, https://github.com/jenkinsci/workflow-cps-plugin/pull/635/files seems suspicious regarding changes from asList and singletonList etc. to List.of which is seen in the stack-trace above.

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