Returned Values from a Process Call are being destroyed

[scott192]

I am posting here and mentioning specific people about the following phenomena I experienced before I went on Annual Leave at my workplace.
I have a complex automation sequence that works 90 percent of the time.  I am aiming to get to 100 percent of the time, but there is a strange bug (happens randomly maybe 2 in 5 times) that causes missing data and stops the automation from completing.
I believe something similar to this behaviour has been looked into before with regard to passing the correct locale and timezone information through various steps in a bot...here we go.

This bot get's triggered as usual.  In STEP 1, a process is called.  Basically, the process returns 4 pieces of information...it's like a LOOKUP, but returns multiple values in one go.  This process executes flawlessly on every time it is called so no problems there.  However, we will return to the bug in a little while.

In STEP 2, an Appscript Task is called.  The task is passed some of the returned values from the previous process as inputs.

Once again, STEP 2 executes every time without problem and returns an object with a number of keys and values.

In STEP 3, values that were returned from the Appscript Task and a value that was returned from the ReadVolume process in STEP 1 are written to the record.  It is in this step that the called process's value has been replaced with an empty string "" or possibly null as this is written to the column.

I have examined the monitor for the bot run and stepped through the list of Inputs and outputs and can verify that the value that should be inserted into the column CFDocID is passed correctly from the process in STEP 1.
Somewhere between STEP 2 and STEP 3, the value is being lost from memory or perhaps being overwritten/dropped in the backend of Appsheet.

Again, this happens randomly...but it is verifiable that the value is passed correctly in STEP 1.

@nico is Appscript Task causing values to be lost in this bot? Possibly?
@AleksiAlkio Any hidden issues you may be aware of that can cause data to be lost during the execution of a bot?
@lizlynch could you do your magic and make sure the correct people see this? 

[Steve]

TL;DR, but in my experience, it seems that saving a change to your app from the app editor will kill any running bots and the result in the loss of the work they were doing at the time.

[scott192]

That could be true Steve, but in this case the bot runs in a completely different app that is not opened in the editor and is intially triggered by using the Appsheet API to change a value in a record that will then start the bot running.

Also, the other values that are written in STEP 3 are correctly stored...

[Trevwiller]

Is the doc ID generated or passed from the Script? I've had script runs that fail to properly pass back data based on the script being formatted slightly incorrect OR all else could happen perfectly, but the last item fails as it either times out and doesn't run that piece or deeper investigation with loggers and a little time for a failed run.

If the script is run asynchronously the bot can fly past it as it took even a millisecond too long to generate. which a wait function can be inserted and to check for the value to be pasted. But it's also good to have for a script in my opinion if a return value is needed as it will allow the script to run as long as needed for its return value.

You could split this into two runs and have one script create the item and one retrieve the doc I'd based on partial name match or key match if it is in the name. This way one script processes one item limiting failures, complexity, and run time of a single script.

Hope this helps. 

[scott192]

Hope my explanation and the screenshot from the process step to @nico has clarified your question about the docid being generated or retrieved without using script.
The script does not run asynchronously though...I really have to send and retrieve values back throughout the whole process.
Your suggestion about splitting the bot into different runs is exactly what I have done with this complex automation.  You can see in the first screenshot that there are 9 separate steps that I have split the automation into and each step calls the next step by setting a key value in a BOT column.
It's a shame the automation doesn't fail every single time as that would point to an error more easily 😁
Thank you for showing an interest in this problem @Trevwiller 

[nico]

Hi Scott, can you please open a ticket with support with the affected app id, and ideally a screenshot of a sample in the monitoring app where you're not seeing the values passed through correctly? Ask that to be sent to the Automation team so it gets routed to my team.

That would help us troubleshoot this issue.

Two reasons I think this could happen:

1. is if your Apps Script is returning a different structure or raising an exception during its run then the return value will just be an empty string. It seems like you've ruled that out already - but worth verifying that's right.

2. Without deviling too much into specifics, there are extra complexities in handling "Call Process" step that might be causing a timing bug on our end here.

[scott192]

From what I can see @nico , TASK 2 is running BEFORE TASK 1 has returned variables back from the called process.
Task 1 looks up and retrieves a documentid from the database (sheets), it then passes that info forward (from the RETURN section of the process and the Appscript Task makes use of that id to open and manipulate the document.
Appscript fails as the documentid is null whereas the process output clearly shows that the correct information has been retrieved.

I will open a ticket and try to explain this again...it's a significant failure rate.  Perhaps there really aren't that many people making use of Call a Process and Return values from a process in the Appsheet community?

[scott192]

It's very strange...This is what a completed process steps run looks like

Can anyone tell me what step number 3 does?  I have examined the data of this step in failed runs and there are some strange things that I don't understand.

[scott192]

Am I to assume that the order of those steps is actually nonsense?

That BoomarkID is only known once the Appscript returns it from step 4!  Which according to that log happens 10 seconds later 😋

[luizluca]

I have already opened a support case:

As per the update from our specialist team, as we informed earlier, that the scheduled bot firstly repeats only app script steps for each record on which the scheduled bot is triggered, and in the last iteration of this loop the further steps get executed, and you can use the AppScript Return value of the last record that is triggered in the last iteration of this process.

It is just because the scheduled bot does batch processing, but the AppScript expects the linear processing, so we will suggest you add one wait step between the AppScript step and its next steps, which is utilizing the return value of the AppScript step, so that the AppScript gets enough time to execute. This is the only possible solution.

Indeed a wait step does allow the code to run nicely during my test (at least for much more rows). However, it smallest one is 5min. Not a nice solution.

If scripts need a time to work in parallel, just incorporate it into the appscript action!

[scott192]

This is kind of a moot suggestion really because my bot doesn't use a schedule.

The information about scheduling you have received is useful though, but is not a solution for anyone who is using appscript in a task of the scheduled bot...nobody is going to add a 5 minute wait step unless the schedule is not per row.

It would be better for Appsheet to put out a notice that Appscript Tasks in Scheduled (Per Row) bots are not supported.  This would lead the developer to do all the processing fully in Appscript and then use the Appsheet API to write any needed changes back to Appsheet...probably a tall order, but all problems are solvable 😁

I think timing issues and memory storage problems are the main factors to look at here as suggested by @nico .  Remember that the automation engine was overhauled to much wailing and gnashing of teeth originally.  A year or so later I find that Processes are incredibly useful and I tend to create processes directly now without starting a Bot.  Perhaps it wasn't tested enough at the time of release?

[scott192]

Hey @nico I have recorded a Google Meet demonstrating the problem.  I have also sent this video to Appsheet Support as I think they are barking up the wrong tree!

https://drive.google.com/file/d/12behHAcgKI-Or2CpCC63BFF-sPJVsdMA/view?usp=sharing

Video so that people can SEE the problem...

[Steve]

Attn @WillowMobileSys, related?

[WillowMobileSys]

@scott192 @luizluca @nico @Trevwiller

@Steve ... Thanks for pulling me into this.  It think my issue may be related.   

For the others, my use case is a Scheduled Bot that calls a Script to retrieve Google Direction Service values - miles and hour.  The Bot has recently been picking up 30 rows to run in batch but only 1 or 2 of them get properly updated EVEN THOUGH the Script return shows correct return values for every row.

A timing issue, where the update step runs prematurely would certainly explain the symptom.  However, when I look at log files it appears to me that the Script return happens WELL before any of the update steps run. 

For example, in last night's run, the LAST Script return was at 3:00:48 AM - according to Google App Script log files.  The FIRST attempt to Save the return values was logged with a timestamp of 3:01:55 AM.   This of course assumes that all timestamps are accurate.  And obviously we don't know what happens INSIDE of the service to "unpack" the Script return values.  Maybe this takes longer than a minute before the values are truly ready for use?

@luizluca mentions that a wait step allows returned value to be applied properly.  I will try this to see if I get similar resolution.  But as he said, a 5 minute wait on every run is infeasible!!

EDITED:  I added a Wait step and all rows updated successfully.  The Wait's did not significantly extend the overall run time.  So this is an acceptable workaround for my scenario - especially since this is a backup and should not really ever need to run at all. 

It should be noted that I have single calls to the same Script in a different app.  Those update EVERY time. 

[Suvrutt_Gurjar]

Just thought of adding another use case where the wait step proved useful.

Solved: Delaying a row creation or a bot action - Google Cloud Community