Inline function triggered by a callback = execution timeout

d.healey

@Lindon @ps Just to confirm we're all doing the same test, here is the snippet I'm using, constructed from ps's code.

HiseSnippet 1170.3ocsV01aaaCDlJIpnVacXEX+.H7mjWbcr255FVVwpisbh5rkDrjqWwvPAqDsMWjHMDoSqwP96ree6C66aGk7aYIHq0.S.1R2a7t64NdjA4hXpTJxQFUhVNmhL9Tyvkb0rNyHLNxsKx3yLGPjJZNtj0YKmSjRZBxv3vy0LLpbDp34O+wyHoDdLcKKD5UBVLsOKio1xM3E+DKMsGIgFwx1Q6m9B2XAuiHUr.hmCMahlShujLk5QzpcfIx3ANILkHOTQTTInyYhjkgyDuiWp+qXR1aSoZhVnPXgJYi5LiklDrNWkHjwQAay7CKy7uvb.Kgsg+VD3yKDf2ZwtXfwA2WH05iHjL1IjNpLjdrYXbNatZqDc77IltbnfLg.P8tgRotnC9qCM6H.M3pFYjKo8xAhMVX+rlMqig+pcpk0ImbBt2HuNQt9d3Ns62206bba7KCAxiwCcBC78BcvQCcO+bmgg31d9QW3LD65AZ5rwTKKFOkwo3IK3wJlfiSEjjeSxsqY86VUBo4WQyaHopyHR5ng8sqNSolK+9SNQJxnpYL9zFwhrpPHUYi5wjzzwL0rychrqtUwp0wUgeq8jsDv8Ex53bpbtfKo0rp.tDWAJFJ6ZmhwVUtt1oUrt1xZSPsJygLwAO1A643zEC4EtmqWW3u9NgaQErsaDdb6P7KGEFAXSG+QA8cVoEHusGNLraM.t54OD222O.Vp1Q3fQgW.Z35E4Wr1sGNr8qwtgEdC7Grhic52+1PWYfqwsTAfA3IrTpD+bbO3c3RXmXViILdhlTZuCyoTUOQZBMeWlgjr4fd0.P6KaP3KWCgsJg5Ih7J1rm27TL6GZ0T+53iKAvJPGjTjRaLOmwU1CHpYMxI7DQlcMssWqAT.D63O.fiHm9uFOxanS+1QPtEzFRa7P+QQ5tjmf8.HvcfCPiGegCzo4OXfimVSfkkEroWpvWQxwADNMsEjrq6egjpiHCJr.gc0Rw51DqxO08TAv1T0PwBEfh1aZKlVffSajjSdW6T1TNMIh9dXMh.3E.feoY8l0AzPpcwXVhZlcsMzWPYSmAEgeEfsXvy4zjpE8P0NcSYRv8DJp+pVb.Mv+aQSlbmxzoVtHMEJT2kX8Hw76yPa9hr2RyqC.V5B5FEgYF2bPzC9vFDEWhz6nnf6xYJ+4zUzEcUIkee6wVnUkJ3qQtcIJhdR1Jdfdyo4JlNbL5RuBNJnbtVEytT4kJw7BcWUegLPUH8Qqm5oqwHF35GZVVuQuGYXZXYfPK0e7GEmlbqolv7ZQxhTh5lCw0mVsR..n2Xxod5HWxTK28zrOhI6Mu2I6eng3iMCXp3Y2cLdvcDi.T++QLt57vGY5LYBMVsM.Oxr2OuuG98e39xMvSg4L4LcQ1aQVHbMfXJ3cNT5k558A51sR5lZZMBDR4IED+M7rRXKMswJgsVKDkQhyEuItbaj9D2GVvAhIdwELp.2zAnwsPEas.6La1nIJCN7+Mww5z+IvNf61luZOr4q2Cad5dXy2rG17r8vlucOr46tWaz26p8BkHqb6.vHvoXFiggCm.cVEcgn+Afiwlu+

Christoph Hart

Ok just to get a little bit more systematic:

both macOS / windows
only the findFiles() call is affected. Using a loop to simulate a heavy task doesn't trigger. BTW, you can use Console.startBenchmark() and Console.stopBenchmark() before and after the loop to find out how long it takes. Try increasing the loop count until the timeout happens and then let me know what's the value that is causing the timeout (it definitely triggers the timeout after a certain period of time).
it happens only if the findFiles() call is happening in a callback. Does it also happen with Engine.showYesNoWindow()? This is the most simple callback to reproduce.

ps

As far as I could reproduce only findFiles() in combination with a loop in the same function leads to timeout when executed by a callback.

But this is getting stranger and stranger. In the meantime I cleaned the build directory - compiled a plugin and after that tried my little dummy code again. Suddenly no timeout (At least not every time... before that it was a sure thing). Once I push the loop harder (1000 instead of 100 values) it's back again. (unless I remove find files or the paint routine). Also in larger projects it seems to be related to the workload of the function somehow.

Where should I place the Console.stopBenchmark() because when I get the timeout it never reaches the stop point.

d.healey

@ps How many files are in the folder you are scanning with findFiles?

Christoph Hart

Where should I place the Console.stopBenchmark() because when I get the timeout it never reaches the stop point.

Remove the findFiles call, then put the stopBenchmark() call after the loop and play around with the loop length to find the spot where it times out. Then check what value it prints for the highest loop count you can get it to run through.

ps

@d-healey I tried different locations with different amounts.

I just searched through 3 big folders taking 300ms without a loop no problem - adding just a dummy loop printing 10 numbers - timeout

and again removing the paint routine - no problem for the full function at all

ps

@Christoph-Hart without the find files function I can torture it about until 5.5mio random numbers taking around 5seconds.

ps

@Christoph-Hart ok wow I just realized I had commented out the paint routine - now that I have the paint routine back in I can only get a fraction of that.

With paint Routine in the script I can make it to 300ms (Yes not seconds) until the timeout

Starting not from the Callback but just calling the function on init I can go up to 5seconds with the paint routine as well

Lindon

Just to note I was also seeing this in functions that were using the .getUserPresetList()

ps

@Lindon do you mind trying if the following code in an otherwise empty script is affected by the fact that the paint routine is commented out or not? Just try what benchmark you can hit with paint routine in and out.
As said for me it's worlds between it just because of the fact that the script contains pr.

/*
const var Panel1 = Content.getComponent("Panel1");

Panel1.setPaintRoutine(function(g)
{
g.drawAlignedText("Test", [0,0,this.getWidth(),this.getHeight()], "centred");	
});
*/

inline function loadjsn()
{
Server.setBaseURL("https://something.com");

Server.callWithGET("/something", "", function(status, response)
{   
 test();   
});  
	
}

loadjsn();

inline function test()
{
Console.startBenchmark();	
Console.print("start");

Console.startBenchmark();	
for (i=0;i<2000000;i++)
{
Math.random();
}
Console.stopBenchmark();
	
}

Lindon

@ps well with the paint routine out and then wiht it in:

Interface: start
Interface: Benchmark Result: 194.833 ms
Interface: Compiled OK
Interface: start
Interface: Benchmark Result: 193.293 ms

Yeah quicker (just) with it in...

ps

@Lindon haha but can you also push it to the same values by raising the number in the loop until you get a timeout?

Lindon

@ps said in Inline function triggered by a callback = execution timeout:

@Lindon haha but can you also push it to the same values by raising the number in the loop until you get a timeout?

yep got you -- set the loop to 9000000 works fine with no paint routine, fails with a paint routine:

Interface: Benchmark Result: 864.576 ms
Interface: Compiled OK
Interface: start
Interface:! Line 30, column 9: Execution timed-out {SW50ZXJmYWNlfHw1MzB8MzB8OQ==}
extimeout:! Line 30, column 9: Execution timed-out

ps

@Lindon ahh thanks for confirming - I assume that also on your end probably it’s around 300ms with the paint routine (which makes the find files function and other functions that need a bit more time run into timeout)

So the question is - why does including a paint routine limit the timeout to such a short time when an inline function get’s called through a callback…

Lindon

@ps said in Inline function triggered by a callback = execution timeout:

@Lindon ahh thanks for confirming - I assume that also on your end probably it’s around 300ms with the paint routine (which makes the find files function and other functions that need a bit more time run into timeout)

So the question is - why does including a paint routine limit the timeout to such a short time when an inline function get’s called through a callback…

damn good question..

I've got it paired down to this and it errors...

inline function test()
{
Console.startBenchmark();	
Console.print("start");

Console.startBenchmark();	
for (i=0;i<2050000;i++)
{
Math.random();
}
Console.stopBenchmark();
	
}```

ps

@Lindon which is based on your benchmark before not a very long time probably - I guess this is a case for @Christoph-Hart now :)

d.healey

@Christoph-Hart is findFiles synchronous?

Lindon

I fiddled around a little more - its in and around the 200ms mark that its failing...sometimes it will make it over 200ms and be OK - but only slightly and very rarely...

Christoph Hart

Alright, I could reproduce the issue. The thing is that there are different timeout values for different callbacks, so the paint routine eg. has a very short timeout value because it's not expected to take longer than 200ms, and if you're writing a paint routine that takes longer than 200ms you'll need to take a step back and evaluate life decisions that led you to the point.

However the timeout is a single value and if you're calling something on another thread (like eg. the server thread), which has a much higher timeout to cope with things like findFiles() etc., it will overwrite the long timeout value with the short paint timeout restriction hence triggering the timeout pretty fast (and scanning 50-100 files quickly exceeds 200ms).

The complicated solution would be to make a thread local value for the timeout so that it won't cause problems like this, but actually I think I'll just forget about the entire concept of different timeouts and just use a single reasonable value like 3 seconds everywhere and then call it a day - the only hard reason for a timeout is to prevent

while(true)
{
    Math.random();
}

from freezing your system and the idea of educating people by not allowing their code to run longer than an arbitrary limit isn't worth the hassle of coping with edge cases like this.

Christoph Hart

Alright, now everything has 5 seconds to complete its task - the only difference is that the onInit callback has a timeout that can be specified in the settings (defaults to 15 seconds).

Also I've bypassed the timeout detection for the findFiles() call as this is a call that has a unbounded maximum execution time so you should be able to scan 10 thousands of files without breaking the timeout limit.

Inline function triggered by a callback = execution timeout

18

1.7k

11.9k

103.4k