workflow-cps-plugin
workflow-cps-plugin copied to clipboard
CpsFlowExecution: parseScript(): log "Method Too Large" situations more readably
A small almost-cosmetic change which makes life easier for my colleagues when they develop (and debug failures of) Jenkins scripted pipelines.
UPDATE: Grew to be not so small, so evicted into a method of its own to constrain changes to other parts of the codebase. Learned a few more tricks over time, as new MTL situations were found in the field.
Out of curiosity, what output does this give you and how is it helpful?
Tests helped me realize that the catch block was a bit naive; the groovy parser returns a special exception class with a collection of errors, one of which (okay, the only one) is the Method Too Large one.
PR updated with handling of both eventualities, and if the only exception in view is the MTL - re-throw with a short message avoiding a wall of text in pipeline log. From self-test console (showing both server log id=... and pipeline log test0), it now complains much more readably, like this:
6.903 [test0 #1] Started
7.635 [id=99] SEVERE o.j.p.w.cps.CpsFlowExecution#parseScript: FAILED to parse WorkflowScript (the pipeline script) due to MethodTooLargeException: Method too large: WorkflowScript.___cps___1 ()Lcom/cloudbees/groovy/cps/impl/CpsFunction;
7.680 [test0 #1] java.lang.RuntimeException: FAILED to parse WorkflowScript (the pipeline script) due to MethodTooLargeException: Method too large: WorkflowScript.___cps___1 ()Lcom/cloudbees/groovy/cps/impl/CpsFunction;
7.680 [test0 #1] at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.parseScript(CpsFlowExecution.java:697)
7.680 [test0 #1] at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.start(CpsFlowExecution.java:586)
7.681 [test0 #1] at org.jenkinsci.plugins.workflow.job.WorkflowRun.run(WorkflowRun.java:335)
7.681 [test0 #1] at hudson.model.ResourceController.execute(ResourceController.java:101)
7.681 [test0 #1] at hudson.model.Executor.run(Executor.java:442)
7.700 [test0 #1] Finished: FAILURE
7.718 [id=27] INFO hudson.lifecycle.Lifecycle#onStatusUpdate: Stopping Jenkins
7.766 [id=27] INFO hudson.lifecycle.Lifecycle#onStatusUpdate: Jenkins stopped
Still got a bit of stack trace from generic handling, but it is reasonably short - the ultimate pipeline devs won't have to scroll up a couple of screenfuls just to learn that their script was too long or complex.
Now that the message is visible to end users, I am open to suggestions how to make it more actionable, and/or if the RuntimeException is the right re-throw wrapper, and of course which color should the bike shed be (or this can all be part of another PR) :D
e.g. to explain about script length or its coding complexity and what to do about it (nesting, amount of stages, separation of methods into JSL classes, etc.); maybe point to a knowledge-base URL for a better maintainable article on the subject (don't want to replace one wall of text in the logs with another, right?)
Out of curiosity, what output does this give you and how is it helpful?
Until today, it was helpful to myself and a few colleagues who may/can/do follow traces of the Jenkins server logs when developing pipelines (testing in private Jenkins instances and those wrapped by IDEs notwithstanding).
After the review comments some months ago (thanks, and sorry for not noticing) and a coding effort today, this should be better visible and more "actionable" to a more general population - now shown as a smaller wall of text right in the pipeline build logs:
5.380 [test0 #1] Started
5.975 [test0 #1] java.lang.RuntimeException: FAILED to parse WorkflowScript
(the pipeline script) due to MethodTooLargeException; please refactor to
simplify code structure and/or move logic to a Jenkins Shared Library:
Method too large: WorkflowScript.___cps___1 ()Lcom/cloudbees/groovy/cps/impl/CpsFunction;
5.975 [test0 #1] at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.parseScript(CpsFlowExecution.java:703)
5.975 [test0 #1] at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.start(CpsFlowExecution.java:584)
5.975 [test0 #1] at org.jenkinsci.plugins.workflow.job.WorkflowRun.run(WorkflowRun.java:335)
5.975 [test0 #1] at hudson.model.ResourceController.execute(ResourceController.java:101)
5.975 [test0 #1] at hudson.model.Executor.run(Executor.java:442)
6.011 [test0 #1] Finished: FAILURE
...which is IMHO a bit more comprehensible than the original (especially the first time you see it):
...
> git checkout -f c391f78bf7ac0d4afffab4f312a3d81cc41577d1 # timeout=10
Commit message: "..."
> git rev-list --no-walk c391f78bf7ac0d4afffab4f312a3d81cc41577d1 # timeout=10
org.codehaus.groovy.control.MultipleCompilationErrorsException: startup failed:
General error during class generation: Method too large: WorkflowScript.___cps___20692 ()Lcom/cloudbees/groovy/cps/impl/CpsFunction;
groovyjarjarasm.asm.MethodTooLargeException: Method too large: WorkflowScript.___cps___20692 ()Lcom/cloudbees/groovy/cps/impl/CpsFunction;
at groovyjarjarasm.asm.MethodWriter.computeMethodInfoSize(MethodWriter.java:2087)
at groovyjarjarasm.asm.ClassWriter.toByteArray(ClassWriter.java:447)
at org.codehaus.groovy.control.CompilationUnit$17.call(CompilationUnit.java:850)
at org.codehaus.groovy.control.CompilationUnit.applyToPrimaryClassNodes(CompilationUnit.java:1087)
at org.codehaus.groovy.control.CompilationUnit.doPhaseOperation(CompilationUnit.java:624)
at org.codehaus.groovy.control.CompilationUnit.processPhaseOperations(CompilationUnit.java:602)
at org.codehaus.groovy.control.CompilationUnit.compile(CompilationUnit.java:579)
at groovy.lang.GroovyClassLoader.doParseClass(GroovyClassLoader.java:323)
at groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:293)
at groovy.lang.GroovyShell.parseClass(GroovyShell.java:677)
at groovy.lang.GroovyShell.parse(GroovyShell.java:689)
at org.jenkinsci.plugins.workflow.cps.CpsGroovyShell.doParse(CpsGroovyShell.java:142)
at org.jenkinsci.plugins.workflow.cps.CpsGroovyShell.reparse(CpsGroovyShell.java:127)
at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.parseScript(CpsFlowExecution.java:554)
at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.start(CpsFlowExecution.java:506)
at org.jenkinsci.plugins.workflow.job.WorkflowRun.run(WorkflowRun.java:335)
at hudson.model.ResourceController.execute(ResourceController.java:101)
at hudson.model.Executor.run(Executor.java:442)
1 error
at org.codehaus.groovy.control.ErrorCollector.failIfErrors(ErrorCollector.java:309)
at org.codehaus.groovy.control.CompilationUnit.applyToPrimaryClassNodes(CompilationUnit.java:1107)
at org.codehaus.groovy.control.CompilationUnit.doPhaseOperation(CompilationUnit.java:624)
at org.codehaus.groovy.control.CompilationUnit.processPhaseOperations(CompilationUnit.java:602)
at org.codehaus.groovy.control.CompilationUnit.compile(CompilationUnit.java:579)
at groovy.lang.GroovyClassLoader.doParseClass(GroovyClassLoader.java:323)
at groovy.lang.GroovyClassLoader.parseClass(GroovyClassLoader.java:293)
at groovy.lang.GroovyShell.parseClass(GroovyShell.java:677)
at groovy.lang.GroovyShell.parse(GroovyShell.java:689)
at org.jenkinsci.plugins.workflow.cps.CpsGroovyShell.doParse(CpsGroovyShell.java:142)
at org.jenkinsci.plugins.workflow.cps.CpsGroovyShell.reparse(CpsGroovyShell.java:127)
at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.parseScript(CpsFlowExecution.java:554)
at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.start(CpsFlowExecution.java:506)
at org.jenkinsci.plugins.workflow.job.WorkflowRun.run(WorkflowRun.java:335)
at hudson.model.ResourceController.execute(ResourceController.java:101)
at hudson.model.Executor.run(Executor.java:442)
Finished: FAILURE
...and requires less scrolling to get to the crux of the issue =D
Sorry it took a while to notice that there was finally a new review here - too many browser tabs open to keep track of such :D
Thanks for doing it!
Hm, got another use-case to handle: managed to get a step definition too large (aka "global variable", anyhow in JSL as vars/cloudBranch.groovy)!
So the pipeline chugged along until it called that step - and that's where the job crashed, with a different exception:
[Pipeline] End of Pipeline
Also: org.jenkinsci.plugins.workflow.actions.ErrorAction$ErrorId: a1490d3b-63d7-4555-ae55-3a0d6856aee6
org.jenkinsci.plugins.workflow.cps.CpsCompilationErrorsException: startup failed:
General error during class generation: Method too large: cloudBranch.___cps___586328 ()Lcom/cloudbees/groovy/cps/impl/CpsFunction;
groovyjarjarasm.asm.MethodTooLargeException: Method too large: cloudBranch.___cps___586328 ()Lcom/cloudbees/groovy/cps/impl/CpsFunction;
at groovyjarjarasm.asm.MethodWriter.computeMethodInfoSize(MethodWriter.java:2087)
at groovyjarjarasm.asm.ClassWriter.toByteArray(ClassWriter.java:447)
at org.codehaus.groovy.control.CompilationUnit$17.call(CompilationUnit.java:850)
at org.codehaus.groovy.control.CompilationUnit.applyToPrimaryClassNodes(CompilationUnit.java:1087)
...
<no further pointers to the class in question>
...
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
at java.base/java.lang.Thread.run(Thread.java:1583)
1 error
at org.codehaus.groovy.control.ErrorCollector.failIfErrors(ErrorCollector.java:309)
at org.codehaus.groovy.control.CompilationUnit.applyToPrimaryClassNodes(CompilationUnit.java:1107)
at org.codehaus.groovy.control.CompilationUnit.doPhaseOperation(CompilationUnit.java:624)
at org.codehaus.groovy.control.CompilationUnit.processPhaseOperations(CompilationUnit.java:602)
at org.codehaus.groovy.control.CompilationUnit.compile(CompilationUnit.java:579)
at groovy.lang.GroovyClassLoader.doParseClass(GroovyClassLoader.java:323)
...
at org.jenkinsci.plugins.workflow.cps.LoggingInvoker.getProperty(LoggingInvoker.java:121)
at com.cloudbees.groovy.cps.impl.PropertyAccessBlock.rawGet(PropertyAccessBlock.java:20)
at WorkflowScript.run(WorkflowScript:428)
at com.cloudbees.groovy.cps.CpsDefaultGroovyMethods.each(CpsDefaultGroovyMethods:2125)
at com.cloudbees.groovy.cps.CpsDefaultGroovyMethods.each(CpsDefaultGroovyMethods:2110)
at com.cloudbees.groovy.cps.CpsDefaultGroovyMethods.each(CpsDefaultGroovyMethods:2163)
at WorkflowScript.run(WorkflowScript:385)
at ___cps.transform___(Native Method)
at com.cloudbees.groovy.cps.impl.PropertyishBlock$ContinuationImpl.get(PropertyishBlock.java:73)
at com.cloudbees.groovy.cps.LValueBlock$GetAdapter.receive(LValueBlock.java:30)
at com.cloudbees.groovy.cps.impl.PropertyishBlock$ContinuationImpl.fixName(PropertyishBlock.java:65)
...
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
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:1583)
Finished: FAILURE
Note there are actually two lines at WorkflowScript.run(WorkflowScript:NNN), pipeline code at line 385 starts an ...each {} closure to iterate several repos this job processes, and the line 428 actually calls the cloudBranch() method.
Gotta look into the structure of CpsCompilationErrorsException to see how to best parse it here (and know if "method too large" was the only error, so the report can be trimmed), and also consider that not only WorkflowScript can have such troubles.
While refactoring that use-case, I've also got a nested hit, with pipeline and several JSL steps being okay, but a further step (evicted code) being too large:
Also: org.jenkinsci.plugins.workflow.actions.ErrorAction$ErrorId: 32491c0c-247d-4340-a173-b778431b7d6a
org.jenkinsci.plugins.workflow.cps.CpsCompilationErrorsException: startup failed:
General error during class generation: Method too large: branchResync.___cps___636753 ()Lcom/cloudbees/groovy/cps/impl/CpsFunction;
groovyjarjarasm.asm.MethodTooLargeException: Method too large: branchResync.___cps___636753 ()Lcom/cloudbees/groovy/cps/impl/CpsFunction;
at groovyjarjarasm.asm.MethodWriter.computeMethodInfoSize(MethodWriter.java:2087)
at groovyjarjarasm.asm.ClassWriter.toByteArray(ClassWriter.java:447)
...
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
at java.base/java.lang.Thread.run(Thread.java:1583)
1 error
at org.codehaus.groovy.control.ErrorCollector.failIfErrors(ErrorCollector.java:309)
at org.codehaus.groovy.control.CompilationUnit.applyToPrimaryClassNodes(CompilationUnit.java:1107)
...
at com.cloudbees.groovy.cps.impl.PropertyAccessBlock.rawGet(PropertyAccessBlock.java:20)
at cloudBranch.resync(cloudBranch.groovy:78)
at cloudBranch.prepareFeatureFreeze(cloudBranch.groovy:220)
at cloudBranch.processFeatureFreeze(cloudBranch.groovy:564)
at WorkflowScript.run(WorkflowScript:428)
at com.cloudbees.groovy.cps.CpsDefaultGroovyMethods.each(CpsDefaultGroovyMethods:2125)
at com.cloudbees.groovy.cps.CpsDefaultGroovyMethods.each(CpsDefaultGroovyMethods:2110)
at com.cloudbees.groovy.cps.CpsDefaultGroovyMethods.each(CpsDefaultGroovyMethods:2163)
at WorkflowScript.run(WorkflowScript:385)
at ___cps.transform___(Native Method)
at com.cloudbees.groovy.cps.impl.PropertyishBlock$ContinuationImpl.get(PropertyishBlock.java:73)
...
And another pattern when the code was moved into a JSL class:
Also: org.jenkinsci.plugins.workflow.actions.ErrorAction$ErrorId: 99b19442-dee8-46d4-8d05-05439214279a
org.jenkinsci.plugins.workflow.cps.CpsCompilationErrorsException: startup failed:
General error during class generation: Method too large: com/myprovys/ci/BranchResync.___cps___679414 ()Lcom/cloudbees/groovy/cps/impl/CpsFunction;
groovyjarjarasm.asm.MethodTooLargeException: Method too large: com/myprovys/ci/BranchResync.___cps___679414 ()Lcom/cloudbees/groovy/cps/impl/CpsFunction;
at groovyjarjarasm.asm.MethodWriter.computeMethodInfoSize(MethodWriter.java:2087)
at groovyjarjarasm.asm.ClassWriter.toByteArray(ClassWriter.java:447)
at org.codehaus.groovy.control.CompilationUnit$17.call(CompilationUnit.java:850)
...
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
at java.base/java.lang.Thread.run(Thread.java:1583)
1 error
at org.codehaus.groovy.control.ErrorCollector.failIfErrors(ErrorCollector.java:309)
at org.codehaus.groovy.control.CompilationUnit.applyToPrimaryClassNodes(CompilationUnit.java:1107)
...
at com.cloudbees.groovy.cps.impl.PropertyAccessBlock.rawGet(PropertyAccessBlock.java:20)
at WorkflowScript.run(WorkflowScript:428)
at com.cloudbees.groovy.cps.CpsDefaultGroovyMethods.each(CpsDefaultGroovyMethods:2125)
at com.cloudbees.groovy.cps.CpsDefaultGroovyMethods.each(CpsDefaultGroovyMethods:2110)
at com.cloudbees.groovy.cps.CpsDefaultGroovyMethods.each(CpsDefaultGroovyMethods:2163)
at WorkflowScript.run(WorkflowScript:385)
at ___cps.transform___(Native Method)
at com.cloudbees.groovy.cps.impl.PropertyishBlock$ContinuationImpl.get(PropertyishBlock.java:73)
...
(here via direct call from pipeline WorkflowScript)
Posted the updated code to recognize the newly seen exception from Method Too Large in a JSL. I'll be testing a build with this on servers I manage, to get some first-hand feedback.
A few things of note are:
- we try to detect the problematic step/class name (if not
WorkflowScript) and make less assumption that specifically the pipeline script code is too large - newly emitted stack trace (to be seen in build log) should include a trail through
*.groovysource files+line numbers, if present (assuming JSL) - logging into server log only goes as FINE(R) so should not be a problem by default (but developers figuring out the issue with a private Jenkins instance can drill into full gory details on demand)
Heh, the code path which leads to MTL stack trace for steps/classes from JSL apparently lands into a different method's try/catch. Reworking the plugin change for the not-WorkflowScript case, although currently inclined to make this handling a method to just call from several places.
Figured it out locally, preparing refactored PR contents as a meaningful series of commits :)
Updated screenshots, now with some detail learned about MTL issues happening in the JSL also:
- Pipeline script too large:
...
Executing git in workdir C:\Users\klimov\.jenkins\workspace\test-MethodTooLarge@libs\3fbaa4c2a74a618783608223aa05bcd2484d251d9f183ec393764a9458686f38
java.lang.RuntimeException: FAILED to parse WorkflowScript (the pipeline script) due to MethodTooLargeException; please refactor to simplify code structure and/or move logic to a Jenkins Shared Library:
-----
org.codehaus.groovy.control.MultipleCompilationErrorsException: startup failed:
General error during class generation: Method too large: WorkflowScript.___cps___5112 ()Lcom/cloudbees/groovy/cps/impl/CpsFunction;
groovyjarjarasm.asm.MethodTooLargeException: Method too large: WorkflowScript.___cps___5112 ()Lcom/cloudbees/groovy/cps/impl/CpsFunction;
-----
Complete details can be seen in server log at FINE/FINER level (Jenkins admin access for org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.MethodTooLargeLogging is required)
Finished: FAILURE
- JSL step:
...
[Pipeline] End of Pipeline
Also: org.jenkinsci.plugins.workflow.actions.ErrorAction$ErrorId: e5f57f7d-1081-49cf-a579-0644086eead0
java.lang.RuntimeException: FAILED to parse presumed JSL step 'cloudBranch' due to MethodTooLargeException; please refactor to simplify code structure:
-----
org.jenkinsci.plugins.workflow.cps.CpsCompilationErrorsException: startup failed:
General error during class generation: Method too large: cloudBranch.___cps___1028 ()Lcom/cloudbees/groovy/cps/impl/CpsFunction;
groovyjarjarasm.asm.MethodTooLargeException: Method too large: cloudBranch.___cps___1028 ()Lcom/cloudbees/groovy/cps/impl/CpsFunction;
-----
Complete details can be seen in server log at FINE/FINER level (Jenkins admin access for org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.MethodTooLargeLogging is required)
Finished: FAILURE
- JSL class:
...
[Pipeline] End of Pipeline
Also: org.jenkinsci.plugins.workflow.actions.ErrorAction$ErrorId: 9338d5ab-bd20-4f09-b81a-2d13b2eaf911
java.lang.RuntimeException: FAILED to parse presumed JSL class 'com/myprovys/ci/BranchResync' due to MethodTooLargeException; please refactor to simplify code structure:
-----
org.jenkinsci.plugins.workflow.cps.CpsCompilationErrorsException: startup failed:
General error during class generation: Method too large: com/myprovys/ci/BranchResync.___cps___2123 ()Lcom/cloudbees/groovy/cps/impl/CpsFunction;
groovyjarjarasm.asm.MethodTooLargeException: Method too large: com/myprovys/ci/BranchResync.___cps___2123 ()Lcom/cloudbees/groovy/cps/impl/CpsFunction;
-----
Complete details can be seen in server log at FINE/FINER level (Jenkins admin access for org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.MethodTooLargeLogging is required)
Finished: FAILURE
Notably, code was made to trace the messages I've seen (and posted earlier above) with "bread-crumbs" to see the code path through the pipeline script and groovy (JSL) files and line numbers (for steps/classes with code too large), only to discover this is slapped on later via ContinuationGroup.fixupStackTrace() called from PropertyishBlock.ContinuationImpl.get() :\
Probably some refactoring can be due to take advantage of that bit. At least, the groovy-cps code is now in the same plugin.
I have no plans to review this. My impression from a very brief look at the code was that it seemed quite complicated, but I am not blocking it. IMO creating a page like https://www.jenkins.io/doc/book/pipeline/cps-method-mismatches/ explaining the situation and recommendations in detail seems like it could help, and then perhaps this code could be simplified to only check the stack trace for the relevant class types and add a suppressed exception that links to that page, accepting potential false positives and not adding the additional context currently added by this PR (but maybe that context is critically useful, IDK).
only check the stack trace for the relevant class types and add a suppressed exception
https://github.com/jenkinsci/workflow-cps-plugin/pull/817#pullrequestreview-2029698582 more or less. IIUC this PR offers the same actionable information as was already there, but formatted differently?
links to that page
Actually a redirect URL like in https://github.com/jenkins-infra/jenkins.io/pull/2290.
I'm not sure how the simple redirect to a wiki page would be better?
Do we not-print a wall of text and redirect to a wiki saying "sometimes the script is too big, guess which one of yours that is"?
Or do we print the wall of text and redirect to a wiki that says same and "here's how to look for a needle in the haystack"?
Currently the changeset pinpoints which pipeline, step or JSL class has upset the parser (finds those needles in the haystack for us), so I am not sure how the other options are better. Surely a Wiki link can be posted "in addition" to this, but "instead" - I am not so excited about that path (even not due to author bias - just due to loss of usability improvement we use for over a year).
UPDATE: Looking back at the comment trail (it has been a while overall), maybe there's a way to simplify code to achieve a similar effect. Also unit tests would be nice, although it can take a while to conjure up some test pipeline/var/class files that do not contain an internal codebase we hit this with.
Not sure when/if I'd get to this - got a big higher-priority backlog of work not yet completed at work and in other projects, and this code (and many similarly stalled PRs) is at least completed as far as practical effect is concerned... just 90% of work remains to fulfill the maintainability (or more esoteric ritual) requirements of the project du-jour...
I guess for now I'll keep remerging master into the PR to use incremental builds, maybe will come back to this eventually (hopefully before retirement), anyone beating me to it and bringing this to completion is very welcome though :)