Uploaded image for project: 'Jenkins'
  1. Jenkins
  2. JENKINS-35308

Improve display of non-AbortException stack traces such as MissingPropertyException

    Details

    • Similar Issues:

      Description

      When a user makes an innocent mistake in pipeline script, the error message is overly intense. It contains too much information that are only relevant for a few people, and that ends up masking important information for users.

      A case in point is JENKINS-33629, but I have heard similar feedback from a number of people:

      groovy.lang.MissingPropertyException: No such property: scm for class: groovy.lang.Binding
          at groovy.lang.Binding.getVariable(Binding.java:62)
          at org.jenkinsci.plugins.scriptsecurity.sandbox.groovy.SandboxInterceptor.onGetProperty(SandboxInterceptor.java:185)
          at org.kohsuke.groovy.sandbox.impl.Checker$4.call(Checker.java:241)
          at org.kohsuke.groovy.sandbox.impl.Checker.checkedGetProperty(Checker.java:238)
          at org.kohsuke.groovy.sandbox.impl.Checker.checkedGetProperty(Checker.java:221)
          at org.kohsuke.groovy.sandbox.impl.Checker.checkedGetProperty(Checker.java:221)
          at com.cloudbees.groovy.cps.sandbox.SandboxInvoker.getProperty(SandboxInvoker.java:23)
          at com.cloudbees.groovy.cps.impl.PropertyAccessBlock.rawGet(PropertyAccessBlock.java:17)
          at WorkflowScript.run(WorkflowScript:16)
          at ___cps.transform___(Native Method)
          at com.cloudbees.groovy.cps.impl.PropertyishBlock$ContinuationImpl.get(PropertyishBlock.java:62)
          at com.cloudbees.groovy.cps.LValueBlock$GetAdapter.receive(LValueBlock.java:30)
          at com.cloudbees.groovy.cps.impl.PropertyishBlock$ContinuationImpl.fixName(PropertyishBlock.java:54)
          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:497)
          at com.cloudbees.groovy.cps.impl.ContinuationPtr$ContinuationImpl.receive(ContinuationPtr.java:72)
          at com.cloudbees.groovy.cps.impl.ConstantBlock.eval(ConstantBlock.java:21)
          at com.cloudbees.groovy.cps.Next.step(Next.java:58)
          at com.cloudbees.groovy.cps.Continuable.run0(Continuable.java:154)
          at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.access$001(SandboxContinuable.java:19)
          at org.jenkinsci.plugins.workflow.cps.SandboxContinuable$1.call(SandboxContinuable.java:33)
          at org.jenkinsci.plugins.workflow.cps.SandboxContinuable$1.call(SandboxContinuable.java:30)
          at org.jenkinsci.plugins.scriptsecurity.sandbox.groovy.GroovySandbox.runInSandbox(GroovySandbox.java:106)
          at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.run0(SandboxContinuable.java:30)
          at org.jenkinsci.plugins.workflow.cps.CpsThread.runNextChunk(CpsThread.java:164)
          at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup.run(CpsThreadGroup.java:277)
          at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup.access$000(CpsThreadGroup.java:77)
          at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$2.call(CpsThreadGroup.java:186)
          at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$2.call(CpsThreadGroup.java:184)
          at org.jenkinsci.plugins.workflow.cps.CpsVmExecutorService$2.call(CpsVmExecutorService.java:47)
          at java.util.concurrent.FutureTask.run(FutureTask.java:266)
          at hudson.remoting.SingleLaneExecutorService$1.run(SingleLaneExecutorService.java:112)
          at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:28)
          at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
          at java.util.concurrent.FutureTask.run(FutureTask.java:266)
          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
          at java.lang.Thread.run(Thread.java:745)
      

      This should really be reported as the following:

      Undefined variable 'scm'
        at Jenkinsfile:16
      

      The full stack trace can be hidden under the "details" button of something similar.

      Attention like this makes a big difference in the impression of pipeline to new users, as everyone makes mistakes and how quickly we can get them unstuck is a critical part of the user experience.

        Attachments

          Issue Links

            Activity

            Hide
            jglick Jesse Glick added a comment -

            Not sure how straightforward this is. Catching MissingPropertyException and specially printing it (when it is the cause for build termination) is easy enough, at least assuming it has not been wrapped in another exception, which I think is not an issue in this case. (Cf. JENKINS-25894.) Getting the property name is also easy.

            Finding the source and line number is another matter. We could look for synthetic stack trace elements and print only those, but we might inadvertently wind up hiding relevant parts. Needs some study to make sure that the simplification would actually work reliably.

            Show
            jglick Jesse Glick added a comment - Not sure how straightforward this is. Catching MissingPropertyException and specially printing it (when it is the cause for build termination) is easy enough, at least assuming it has not been wrapped in another exception, which I think is not an issue in this case. (Cf. JENKINS-25894 .) Getting the property name is also easy. Finding the source and line number is another matter. We could look for synthetic stack trace elements and print only those, but we might inadvertently wind up hiding relevant parts. Needs some study to make sure that the simplification would actually work reliably.
            Hide
            michaelneale Michael Neale added a comment -

            I think even if the line number wasn't easy just having a shorter message with the undefined/missing variable would be enough of a hint for most pipelines (line numbers awesome, but perhaps one thing at a time).

            Show
            michaelneale Michael Neale added a comment - I think even if the line number wasn't easy just having a shorter message with the undefined/missing variable would be enough of a hint for most pipelines (line numbers awesome, but perhaps one thing at a time).
            Hide
            ringerc Craig Ringer added a comment -

            People who get stuck here, check for WorkflowScript in your stack traces. That's your Jenkinsfile.

            This has caused me a lot of difficulty as I learn to work with pipelines, though knowing the above makes life much easier. So a big +1 for improving it. *I worked around it in my pipelines; see below for code*.

            The simplest improvement would be to use [StackTraceUtils](http://docs.groovy-lang.org/latest/html/api/org/codehaus/groovy/runtime/StackTraceUtils.html) to sanitize the Groovy stuff. It could also use `StackTraceUtils.addClassTest(...)` to filter out some limited Jenkins and pipeline internals, though some care is needed not to remove important info "above" the application failure.

            Can't Jenkins potentially just walk the stack trace and transform `WorkflowScript` to the `${pipeline-script}` name, or annotate the name with the script-name?  That alone would be a huge help, and pretty simple.

            Bonus points for abbreviating stack traces at `WorkflowScript.run`with a `...` - the rest of the stack isn't really that interesting if you know you got to the point of successful pipeline execution.

            I tried to work around it in my Groovy scripts with an outer try/catch block in which I ran:

            try {
              // pipeline here
            } catch (e) {
              currentBuild.result = 'FAILURE'
              StackTraceUtils.sanitize(e)
              throw e
            }
            

            ... but it doesn't seem to remove anything much. Even when I add my own class filters (see below). Using `StackTraceUtils.printSanitizedStackTrace(e)` has the same effect.

            Note that the docs for StackTraceUtils.sanitize appear to be wrong. It doesn't return the exception - it returns null. Attempting to

               // this is wrong, do not do this
               throw StackTraceUtils.sanitize(e)
            

            will yield the amazingly uninformative exception:

            java.lang.NullPointerException
            	at com.cloudbees.groovy.cps.impl.ThrowBlock$1.receive(ThrowBlock.java:42)
                    ....
            

            when you try to throw null.

            I also wrote a filter to cut some of the crud out:

            StackTraceUtils.addClassTest({
              def result
              switch (it) {
                /* The Jenkinsfile itself */
                case 'WorkflowScript':
                  result = true
                  break
                /* Innards we don't care about */
                case ~/^org.jenkinsci.plugins.workflow/:
                  result = false
                  break
                case ~/^org.jenkinsci.plugins.scriptsecurity.sandbox.groovy.GroovySandbox/:
                  result = false
                  break
                case ~/^hudson.remoting/:
                  result = false
                  break
                case ~/^jenkins.util.ContextResettingExecutorService/:
                  result = false
                  break
                case ~/^jenkins.security.ImpersonatingExecutorService/:
                  result = false
                  break
                default:
                  result = null
                  break
              }
              return result
            })
            

            ... but it's not doing much yet.

            Note that you'll have to approve the required static methods in Jenkins script approvals. (You'll be prompted in the console output on build failure). Or you can just add

            staticMethod org.codehaus.groovy.runtime.StackTraceUtils addClassTest groovy.lang.Closure
            staticMethod org.codehaus.groovy.runtime.StackTraceUtils sanitize java.lang.Throwable
            

            in /jenkins/scriptApproval/ .

            So in short, why is a simple "undefined variable" quite this verbose and hard?

            Show
            ringerc Craig Ringer added a comment - People who get stuck here, check for WorkflowScript in your stack traces. That's your Jenkinsfile. This has caused me a lot of difficulty as I learn to work with pipelines, though knowing the above makes life much easier. So a big +1 for improving it. * I worked around it in my pipelines; see below for code *. The simplest improvement would be to use [StackTraceUtils] ( http://docs.groovy-lang.org/latest/html/api/org/codehaus/groovy/runtime/StackTraceUtils.html ) to sanitize the Groovy stuff. It could also use `StackTraceUtils.addClassTest(...)` to filter out some limited Jenkins and pipeline internals, though some care is needed not to remove important info "above" the application failure. Can't Jenkins potentially just walk the stack trace and transform `WorkflowScript` to the `${pipeline-script}` name, or annotate the name with the script-name?  That alone would be a huge help, and pretty simple. Bonus points for abbreviating stack traces at `WorkflowScript.run`with a `...` - the rest of the stack isn't really that interesting if you know you got to the point of successful pipeline execution. I tried to work around it in my Groovy scripts with an outer try/catch block in which I ran: try { // pipeline here } catch (e) { currentBuild.result = 'FAILURE' StackTraceUtils.sanitize(e) throw e } ... but it doesn't seem to remove anything much. Even when I add my own class filters (see below). Using `StackTraceUtils.printSanitizedStackTrace(e)` has the same effect. Note that the docs for StackTraceUtils.sanitize appear to be wrong. It doesn't return the exception - it returns null. Attempting to // this is wrong, do not do this throw StackTraceUtils.sanitize(e) will yield the amazingly uninformative exception: java.lang.NullPointerException at com.cloudbees.groovy.cps.impl.ThrowBlock$1.receive(ThrowBlock.java:42) .... when you try to throw null. I also wrote a filter to cut some of the crud out: StackTraceUtils.addClassTest({ def result switch (it) { /* The Jenkinsfile itself */ case 'WorkflowScript' : result = true break /* Innards we don't care about */ case ~/^org.jenkinsci.plugins.workflow/: result = false break case ~/^org.jenkinsci.plugins.scriptsecurity.sandbox.groovy.GroovySandbox/: result = false break case ~/^hudson.remoting/: result = false break case ~/^jenkins.util.ContextResettingExecutorService/: result = false break case ~/^jenkins.security.ImpersonatingExecutorService/: result = false break default : result = null break } return result }) ... but it's not doing much yet. Note that you'll have to approve the required static methods in Jenkins script approvals. (You'll be prompted in the console output on build failure). Or you can just add staticMethod org.codehaus.groovy.runtime.StackTraceUtils addClassTest groovy.lang.Closure staticMethod org.codehaus.groovy.runtime.StackTraceUtils sanitize java.lang.Throwable in /jenkins/scriptApproval/ . So in short, why is a simple "undefined variable" quite this verbose and hard?
            Hide
            cowlinator p cowlinator added a comment -

            "People who get stuck here, check for WorkflowScript in your stack traces. That's your Jenkinsfile."

            This.  This should be documented in large font on the main Pipeline/Jenkinsfile documentation home page.

            Show
            cowlinator p cowlinator added a comment - " People who get stuck here, check for WorkflowScript in your stack traces. That's your Jenkinsfile. " This.  This should be documented in large font on the main Pipeline/Jenkinsfile documentation home page.
            Hide
            jglick Jesse Glick added a comment -

            JENKINS-31838 already tracks the poor filenames in stack traces.

            Show
            jglick Jesse Glick added a comment - JENKINS-31838 already tracks the poor filenames in stack traces.

              People

              • Assignee:
                jglick Jesse Glick
                Reporter:
                kohsuke Kohsuke Kawaguchi
              • Votes:
                3 Vote for this issue
                Watchers:
                10 Start watching this issue

                Dates

                • Created:
                  Updated: