Functions seem broken

[steep urchin]

I have a function that tries to add documents to a collection, first I wrote the function to check if the document exists by ID and if so, not add it. After the first run the async queue went sideways and all my other async function went on "waiting" for a few minutes, completely broke production. Then I did a "try catch" to write a document and if Doc ID exists it will catch but that also after first few runs sent rest of my async functions on "waiting". Just to be clear, working with Dart runtimes and the number of check can in the tens of thousands and fails can be as well but I would not expect the system to then take a 20 minute breather to recover.

Not sure why since none of the container logs point me to a direction as to why it happens but if you stress the function out with too much database checks and fails the whole thing goes on a waiting spree and everything async stops.

has anyone else faced this and has a work around ?

[humble slate]

Async functions work via a queue. Is your first execution still executing?

[steep urchin]

nope all function have a 60 second timeout so I wouldn't expect the function to still be active once the Appwrite console says it failed. Also to the queue point, is there as way to clear the queue so PROD doesnt grind to a halt ?

[humble slate]

Clear the queue? Go into redis and clear things

How exactly are you executing the function?

For logs, maybe you can look at the function worker logs

[steep urchin]

These are CRON functions that do the updates and some function are trigger based function that are supposed to spin up when, say a user registers. The annoyance is if my CRON function can cause my trigger function to not trigger cos now they are waiting for something it breaks things. I would really request someone to try this and try to figure out a root cause cos a failed aync function shouldnt cause the complete async function to queue to grind to a halt for a long time.

[humble slate]

These are the latest logs while this function is executing?

Why is it executing for 4 minutes?

[steep urchin]

Yup logs right now. I have no clue, and the PROD is now halted cos things dont trigger anymore ..

[steep urchin]

nothing is executing .. the functions are waiting for, god knows what.

[humble slate]

These logs indicate some function is processing

[steep urchin]

Then you need to tell how to check what is, cos I know nothing else is executing. Also, its not only that async function are severely delayed they are now delayed perpetually, so even when they finally trigger 10 minutes in, the next trigger again waits for something

[humble slate]

Look through all your functions to see what might be executing?

[steep urchin]

Already did before I decided to post here. Only have 13 function so I know exactly wat they are upto. Can you please at least try to reproduce what I am saying cos for me its happening as we speak.

[steep urchin]

Now working on getting rid of any async trigger based things cos its way too finicky.

[steep urchin]

Openruntime executer log, not sure if this is supposed to point to something

[humble slate]

this is the end of the function worker log? or is there anything else below?

[steep urchin]

Nope function worker log had nothing special apart from what’s in the screenshot. You can easily recreate the issue. Just bombard the database with a ton of writes via a dart function (Not sure if the issue is dart only or all runtimes).. trigger the function a few times and after 10 - 15 runs all asynchronous function will start going in waiting status ..

[humble slate]

I don't expect anything special. More so what's at the end.

What's your function timeout?

And how are you triggering the function?

[steep urchin]

Function timeout is 60 secs usually but when the issue occurs it doesn’t matter since all function requests go on waiting.

Trigger is usually a document write or a new user registration and once the issue starts I can trigger executes from console and all go on waiting.

[humble slate]

What's "a ton of writes"?

[steep urchin]

Well in my case it was about 100k document writes per function run

[steep urchin]

Worked a few times and then suddenly everything stopping and went on waiting

[humble slate]

Well if you have 10-15 of these running, it could take 20 minutes to get through it all

[tranquil vapor]

100k writes is a sh*t ton holy moly haha

[steep urchin]

Not all function write all this data. This is a specific function that’s triggered by a cron schedule every 4 hours to populate a collection with data. I was updating a testing this function in prod and ran it a few too many times and suddenly all async functions stopped. No matter if they are triggered by database write or user session or console trigger..

[steep urchin]

And what do you mean it would take 15 - 20 minutes ? I have the function running right now. It trigger every 4 hours and write about 40k documents in under 2 minutes. No issues at all. However if I trigger it one to many times back to back it will stop all functions and will take a few hours till all functions recover

[humble slate]

Async function executions like executions triggered by a schedule, event, or via the Console are queued and processed serially

[steep urchin]

But if on the console function say execution failed or completed then I would assume nothing is running.. when I was facing the issue I checked and no functions were running only waiting so serial execution stopped.

[humble slate]

I wonder if the executor or function is still stuck processing. Next time it happens, please share the end of the worker logs

docker compose logs --timestamps --tail 10 appwrite-worker-functions

[steep urchin]

Let me see if I can pull logs from a week ago

[humble slate]

Current, as it's happening, logs would be needed

[steep urchin]

Ah ok let me see when I get motivated enough to induce it on a test server.

[steep urchin]

Maybe over the weekend when I have time

[steep urchin]

Happening again attached the requested logs. As mentioned last time nothing special in functions logs

It happened right after a function that dumps / tries to dump a ton of data into the database failed due to timeout. The previous execution failed 15 minutes before I tried executing again and it went “waiting”

[humble slate]

So the logs indicate it's still processing that job

I would have expected a "fetched 13 jobs" or something like that

Since it can't, maybe it's stuck here: https://github.com/appwrite/appwrite/blob/5ddc705099a7751b12432f37d1b0f0381c9aecfa/src/Appwrite/Platform/Workers/Functions.php#L104.

Is your database still running okay?

[steep urchin]

The final "Received Job" would be the one waiting in the console. Not sure what it is waiting on. While its waits everything runs fine, including the database.

If you need me to fetch DB logs I can do that next time

[humble slate]

so weird...this makes no sense...it shouldn't be a cache problem because this find('functions') doesn't use the cache...

Actually wait..can you lookup that job in redis to see the details about it. the keys *66aa......573 should give you the key and then you can run get <key>

this should tell you if it's that function and that it's triggered by http. in that case, it would be this code being triggered.

and then maybe you can modify the source code to log some more info

[steep urchin]

Sorry but you will have to give me a bit more specific instructions on how I can lookup that job in Redis and everything else you mentioned

[misty harness]

How familiar are you with docker?

[steep urchin]

Not a lot, most my exposure is troubleshooting appwrite issues, learning from the fine folks here and reading about it when required.

[misty harness]

gotcha, I would run

docker ps
# copy the container ID of redis or you can use the name of it
docker exec -it <containerId> /bin/sh <-- # this puts you into the container, if redis then redis

https://redis.io/docs/latest/commands/keys/

then you use redis commands

because that container has the redis server

you might be able to just use the appwrite container as they are networked together and it's using redis