When does the following code line end?
subScript.StartScript();
I’m getting unexpected API Automation Script Timeouts and I suspect them due to running SubScript at the end.
Could it be that this line of code is blocked until the execution of the c# logic is started?
There are cases where this can take some time. e.g. tons of scripts are already running and are queuing up in the automation queue.
I’m running the subscript with the following attributes and I would expect it will not block on the method as soon as the script is added the automation queue.
- Synchronous = false;
- PerformChecks = false;
The comment in the timeout error in information event, indicates that it timed out when running the StartScript() hence my suspicion that this is blocked (and delayed) due to tons of other scripts that first need to be executed.
(Code: 0x80131500) Skyline.DataMiner.Automation.ScriptTimeoutException: Script has been running for too long, and is being aborted.
at Skyline.DataMiner.Automation.ThreadWatcher.CheckIfAborted(Thread thread)
at Skyline.DataMiner.Automation.Engine.InternalLaunchSubScript(String scriptName, List`1 finalOptions, Int32 inheritSubScript, Int32 extendedErrorInfo, Dictionary`2& subScriptOutput, List`1& errorMessages)
at Skyline.DataMiner.Automation.SubScriptOptions.StartScript()
at xxxxx.TriggerAsyncScriptExecution(String logContent)
at xxxxx()
at xxxxx()
at xxxxx_1.Script.OnApiTrigger(IEngine engine, ApiTriggerInput requestData)
Hi Mieke,
This method will not wait until the script starts if called with the ‘Synchronous’ option set to false. The execution will be added to the queue and will return. If a point is reached where the max. amount of parallel scripts is reached, this should still not prevent the method from returning.
However, before the execution can be queued, it does need to acquire a lock that protects the protocol and element caches in SLAutomation. If a lot of things are going on, it could happen that these locks are momentarily not available and that the main script will need to wait until they are available. I would not expect this to take minutes, but more like seconds at most.
When I look at the stack trace, it seems that the main script is getting aborted when the ‘CheckIfAborted’ method is called, which checks if the main script has reached the timeout. This method is called before the execution of the subscript is requested, which means that the main script has reached the timeout due to actions before calling this subscript. Can you check if there is anything before that line that may be stuck for some time?
The timeout system starts counting only when the C# block is executed. The script thread is registered to the timeout system right before the ‘Run’ method (or other entry point) is called. I would thus expect that the timeout time should be correctly measured regardless of how long the script would have been queued.
Hi Mieke,
The subScript.StartScript(); returns when:
- The synchronous flag is passed to the subscript as true and the subscript has completed
- Immediately after starting the subscript if the Synchronous flag is passed as false
However, what you describe does not seem to follow these conditions.
Could you confirm if any line below that call gets reached with something like a log?
The only reason I see for the flow to not proceed is if SLNet is too busy to process the request or if SLAutomation is experiencing an issue. Could you confirm if you see any error or notice that could justify this?
I can’t really add a log line as this would massively overload my system with logs.
Keep in mind that this usually happens when there is a very high load of (api) automation scripts to execute.
Will a try – catch around the StartScript() trigger on the mentioned exception?
in that case I could create an information event only when the exception occurs.
My first impression would be that the TryCatch block would not catch that exception given that you are starting your subscript asynchronously.
Although, with the behavior you are describing it may be able to catch the exception, however, keep in mind that if the subscript has timed out it is likely that enough time has elapsed so that your main script also will timeout so it could be worth looking into overriding the default timeout of your main script with engine.Timeout (reference: https://docs.dataminer.services/develop/api/types/Skyline.DataMiner.Automation.Engine.Timeout.html?q=engine.timeout)
Or alternatively, calling engine.KeepAlive() that will reset the elapsed time (reference: https://docs.dataminer.services/develop/api/types/Skyline.DataMiner.Automation.Engine.KeepAlive.html)
thank you! this is giving me so much extra insights.
I’ll have a look at the main script.
A follow-up question: does the Automation Timeout time count from when the c# logic starts to run or when the automation-to-run is added to the Automation-Queue?
In case of the latter, I assume there could be that there are too many items on that queue to get executed in combo with long(er) execution times of (some) of those scripts to run leading to “my script” to timeout even when the c# logic has only run a few seconds.