More robust SPIN errors

StephenOTT · July 17, 2017, 2:16pm

Current SPIN often produces cryptic errors.

Example SPIN may say it was expecting a array but received a object, but does not provide you with the string that was attempted to be parsed, or does not provide where the error occurs (line numbers, events, location in the BPMN, etc).

This creates the need to write lots of redundant catching for errors with unique error names inorder to debug.

@camunda has there been any discussions around adding more robust error messages for SPIN, and what that may look like?

Thanks

thorben · July 19, 2017, 3:31pm

Hi Stephen,

There are currently no ongoing development efforts in Spin. To understand your concenrn, could you please give an example of

A Spin API interaction
The exception that the current Spin version throws
The exception that you would like to see?

Cheers,
Thorben

StephenOTT · July 19, 2017, 3:50pm

@thorben I will put a few real examples together for you but common examples that come to mind:

When using HTTP-Connector, and you are parsing the Response, or parsing Input variables for the configuration of http-connector, what you see if a generic SPIN error which does not give you the location of the error in the activity, no line numbers, etc. Example: if you parse with Spin in the URL parameter, and the response parameter and one of those fails, you do not know which failed. You have to add additional try and catch to handle this.
SPIN will not provide you string output of what was attempted to be parsed when throwing the error. So you may get something like SPIN got object but expected array, but there is not additional error information such as a print of the data passed into S(), so you have to add additional try and catch with system.out to provide the needed debugging information.

thorben · July 19, 2017, 3:57pm

Your first example confuse me a little. Is this about

line numbers in BPMN XML?
line numbers in scripts (potentially embedded in BPMN XML)?
line numbers in the data that is wrapped by the Spin API?

Looking forward to more concrete examples, this would certainly clear things up.

StephenOTT · July 19, 2017, 4:06pm

Yes, line numbers in BPMN XML?
Yes, line numbers in scripts (potentially embedded in BPMN XML)?
Yes, line numbers in the data that is wrapped by the Spin API?

I have to create some of the errors i have run into, to provide the example range of examples,

But generally (with a few exceptions), locating the S() that is throwing the error requires wrapping all your S() in try/catch because the output from SPIN errors is cryptic at best, especially when dealing with lots of data that is similar and coming from many different locations and being merged together. Example in a single listener or input/out variable you may be using SPIN to parse, or you may be access SPIN variable properties, and merging, appending to arrays, navigating arrays, etc. There could be 10+ different uses of the SPIN framework. When something fails, there is not much to go on.

See the attached mocked example. parse_spin_errors.bpmn (4.9 KB)

When you start the process (asyc before on the start event), you get the follow incident:

org.camunda.spin.json.SpinJsonDataFormatException: SPIN/JACKSON-JSON-01001 Unable to parse input into json node
	at org.camunda.spin.impl.json.jackson.JacksonJsonLogger.unableToParseInput(JacksonJsonLogger.java:38)
	at org.camunda.spin.impl.json.jackson.format.JacksonJsonDataFormatReader.readInput(JacksonJsonDataFormatReader.java:46)
	at org.camunda.spin.impl.SpinFactoryImpl.createSpinFromReader(SpinFactoryImpl.java:155)
	at org.camunda.spin.impl.SpinFactoryImpl.createSpin(SpinFactoryImpl.java:69)
	at org.camunda.spin.impl.SpinFactoryImpl.createSpinFromReader(SpinFactoryImpl.java:130)
	at org.camunda.spin.impl.SpinFactoryImpl.createSpin(SpinFactoryImpl.java:50)
	at org.camunda.spin.impl.SpinFactoryImpl.createSpinFromString(SpinFactoryImpl.java:103)
	at org.camunda.spin.impl.SpinFactoryImpl.createSpin(SpinFactoryImpl.java:47)
	at org.camunda.spin.Spin.S(Spin.java:64)
	at jdk.nashorn.internal.scripts.Script$11$\^eval\_.:program(<eval>:5)
	at jdk.nashorn.internal.runtime.ScriptFunctionData.invoke(ScriptFunctionData.java:637)
	at jdk.nashorn.internal.runtime.ScriptFunction.invoke(ScriptFunction.java:494)
	at jdk.nashorn.internal.runtime.ScriptRuntime.apply(ScriptRuntime.java:393)
	at jdk.nashorn.api.scripting.NashornScriptEngine.evalImpl(NashornScriptEngine.java:449)
	at jdk.nashorn.api.scripting.NashornScriptEngine.evalImpl(NashornScriptEngine.java:406)
	at jdk.nashorn.api.scripting.NashornScriptEngine.evalImpl(NashornScriptEngine.java:402)
	at jdk.nashorn.api.scripting.NashornScriptEngine.eval(NashornScriptEngine.java:155)
	at javax.script.AbstractScriptEngine.eval(AbstractScriptEngine.java:233)
	at org.camunda.bpm.engine.impl.scripting.SourceExecutableScript.evaluateScript(SourceExecutableScript.java:114)
	at org.camunda.bpm.engine.impl.scripting.SourceExecutableScript.evaluate(SourceExecutableScript.java:60)
	at org.camunda.bpm.engine.impl.scripting.ExecutableScript.execute(ExecutableScript.java:56)
	at org.camunda.bpm.engine.impl.scripting.env.ScriptingEnvironment.execute(ScriptingEnvironment.java:97)
	at org.camunda.bpm.engine.impl.scripting.env.ScriptingEnvironment.execute(ScriptingEnvironment.java:83)
	at org.camunda.bpm.engine.impl.delegate.ScriptInvocation.invoke(ScriptInvocation.java:40)
	at org.camunda.bpm.engine.impl.delegate.DelegateInvocation.proceed(DelegateInvocation.java:54)
	at org.camunda.bpm.engine.impl.delegate.DefaultDelegateInterceptor.handleInvocationInContext(DefaultDelegateInterceptor.java:87)
	at org.camunda.bpm.engine.impl.delegate.DefaultDelegateInterceptor.handleInvocation(DefaultDelegateInterceptor.java:59)
	at org.camunda.bpm.engine.impl.bpmn.listener.ScriptExecutionListener.notify(ScriptExecutionListener.java:37)
	at org.camunda.bpm.engine.impl.bpmn.listener.ScriptExecutionListener.notify(ScriptExecutionListener.java:27)
	at org.camunda.bpm.engine.impl.core.instance.CoreExecution.invokeListener(CoreExecution.java:95)
	at org.camunda.bpm.engine.impl.core.operation.AbstractEventAtomicOperation.execute(AbstractEventAtomicOperation.java:52)
	at org.camunda.bpm.engine.impl.interceptor.AtomicOperationInvocation.execute(AtomicOperationInvocation.java:89)
	at org.camunda.bpm.engine.impl.interceptor.CommandInvocationContext.invokeNext(CommandInvocationContext.java:125)
	at org.camunda.bpm.engine.impl.interceptor.CommandInvocationContext.performNext(CommandInvocationContext.java:104)
	at org.camunda.bpm.engine.impl.interceptor.CommandInvocationContext.performOperation(CommandInvocationContext.java:79)
	at org.camunda.bpm.engine.impl.interceptor.CommandInvocationContext.performOperation(CommandInvocationContext.java:69)
	at org.camunda.bpm.engine.impl.persistence.entity.ExecutionEntity.performOperationSync(ExecutionEntity.java:622)
	at org.camunda.bpm.engine.impl.persistence.entity.ExecutionEntity.performOperationSync(ExecutionEntity.java:597)
	at org.camunda.bpm.engine.impl.core.operation.AbstractEventAtomicOperation.execute(AbstractEventAtomicOperation.java:58)
	at org.camunda.bpm.engine.impl.interceptor.AtomicOperationInvocation.execute(AtomicOperationInvocation.java:89)
	at org.camunda.bpm.engine.impl.interceptor.CommandInvocationContext.invokeNext(CommandInvocationContext.java:125)
	at org.camunda.bpm.engine.impl.interceptor.CommandInvocationContext.performNext(CommandInvocationContext.java:104)
	at org.camunda.bpm.engine.impl.interceptor.CommandInvocationContext.performOperation(CommandInvocationContext.java:79)
	at org.camunda.bpm.engine.impl.persistence.entity.ExecutionEntity.performOperation(ExecutionEntity.java:611)
	at org.camunda.bpm.engine.impl.persistence.entity.ExecutionEntity.performOperation(ExecutionEntity.java:587)
	at org.camunda.bpm.engine.impl.pvm.runtime.operation.PvmAtomicOperationTransitionCreateScope.scopeCreated(PvmAtomicOperationTransitionCreateScope.java:34)
	at org.camunda.bpm.engine.impl.pvm.runtime.operation.PvmAtomicOperationCreateScope.execute(PvmAtomicOperationCreateScope.java:50)
	at org.camunda.bpm.engine.impl.pvm.runtime.operation.PvmAtomicOperationCreateScope.execute(PvmAtomicOperationCreateScope.java:24)
	at org.camunda.bpm.engine.impl.interceptor.AtomicOperationInvocation.execute(AtomicOperationInvocation.java:89)
	at org.camunda.bpm.engine.impl.interceptor.CommandInvocationContext.invokeNext(CommandInvocationContext.java:125)
	at org.camunda.bpm.engine.impl.interceptor.CommandInvocationContext.performNext(CommandInvocationContext.java:112)
	at org.camunda.bpm.engine.impl.interceptor.CommandInvocationContext.performOperation(CommandInvocationContext.java:79)
	at org.camunda.bpm.engine.impl.interceptor.CommandInvocationContext.performOperation(CommandInvocationContext.java:69)
	at org.camunda.bpm.engine.impl.jobexecutor.AsyncContinuationJobHandler.execute(AsyncContinuationJobHandler.java:76)
	at org.camunda.bpm.engine.impl.jobexecutor.AsyncContinuationJobHandler.execute(AsyncContinuationJobHandler.java:36)
	at org.camunda.bpm.engine.impl.persistence.entity.JobEntity.execute(JobEntity.java:129)
	at org.camunda.bpm.engine.impl.cmd.ExecuteJobsCmd.execute(ExecuteJobsCmd.java:99)
	at org.camunda.bpm.engine.impl.cmd.ExecuteJobsCmd.execute(ExecuteJobsCmd.java:36)
	at org.camunda.bpm.engine.impl.interceptor.CommandExecutorImpl.execute(CommandExecutorImpl.java:24)
	at org.camunda.bpm.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:104)
	at org.camunda.bpm.engine.impl.interceptor.ProcessApplicationContextInterceptor.execute(ProcessApplicationContextInterceptor.java:66)
	at org.camunda.bpm.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:30)
	at org.camunda.bpm.engine.impl.jobexecutor.ExecuteJobHelper.executeJob(ExecuteJobHelper.java:36)
	at org.camunda.bpm.engine.impl.jobexecutor.ExecuteJobHelper.executeJob(ExecuteJobHelper.java:29)
	at org.camunda.bpm.engine.impl.jobexecutor.ExecuteJobsRunnable.executeJob(ExecuteJobsRunnable.java:88)
	at org.camunda.bpm.engine.impl.jobexecutor.ExecuteJobsRunnable.run(ExecuteJobsRunnable.java:57)
	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:748)
Caused by: spinjar.com.fasterxml.jackson.core.JsonParseException: Unrecognized token 'value1': was expecting ('true', 'false' or 'null')
 at [Source: org.camunda.spin.impl.util.RewindableReader@438d18a0; line: 1, column: 15]
	at spinjar.com.fasterxml.jackson.core.JsonParser._constructError(JsonParser.java:1581)
	at spinjar.com.fasterxml.jackson.core.base.ParserMinimalBase._reportError(ParserMinimalBase.java:533)
	at spinjar.com.fasterxml.jackson.core.json.ReaderBasedJsonParser._reportInvalidToken(ReaderBasedJsonParser.java:2462)
	at spinjar.com.fasterxml.jackson.core.json.ReaderBasedJsonParser._handleOddValue(ReaderBasedJsonParser.java:1621)
	at spinjar.com.fasterxml.jackson.core.json.ReaderBasedJsonParser.nextFieldName(ReaderBasedJsonParser.java:828)
	at spinjar.com.fasterxml.jackson.databind.deser.std.BaseNodeDeserializer.deserializeObject(JsonNodeDeserializer.java:208)
	at spinjar.com.fasterxml.jackson.databind.deser.std.JsonNodeDeserializer.deserialize(JsonNodeDeserializer.java:69)
	at spinjar.com.fasterxml.jackson.databind.deser.std.JsonNodeDeserializer.deserialize(JsonNodeDeserializer.java:15)
	at spinjar.com.fasterxml.jackson.databind.ObjectMapper._readMapAndClose(ObjectMapper.java:3736)
	at spinjar.com.fasterxml.jackson.databind.ObjectMapper.readTree(ObjectMapper.java:2241)
	at org.camunda.spin.impl.json.jackson.format.JacksonJsonDataFormatReader.readInput(JacksonJsonDataFormatReader.java:43)
	... 67 more

There is a script executing, start and end listeners, and a output parameter. Which one failed based on reading the error message?

edit: A common example i that comes to mind for parsing the Response variable or http-connector is handling what happens when non-json or bad-json is returned:

you are handling your responses with something like S(response)
You do not want to save the response as a string variable because it will be larger than 4000 characters.
So when S(response) fails, how do you know what the value of response was?
If the default print of the error was something like the value of response + the SPIN error message, than you can more easily debug without having to go back and add additional error debug code on top of the existing SPIN debug messages.

system · January 30, 2024, 10:55am