Background job logs seem delayed
It wouldn't be possible for this action to return this output without more logs showing:
https://tapestry-stitch.gadget.app/edit/dev-kalen/queues/job-R22HsY15ZdHvJcRg1JzVE
https://tapestry-stitch.gadget.app/edit/dev-kalen/logs?logql=%7Benvironment_id%3D%22468181%22%7D%20%7C%20json%20%7C%20level%3D~%22info%7Cwarn%7Cerror%22%20%7C%20backgroundActionId%3D%22job-R22HsY15ZdHvJcRg1JzVE%22&timeRange%5Binput%5D=Since%202025-06-11T18%3A22%3A13.660Z
This was happening repeatedly when testing for the last 15 minutes or so - however just now as I'm testing it's now working correctly. Was there a hiccup with the background jobs?
Gadget Auth - Loading
Gadget Auth
Gadget Auth - Loading
Gadget Auth
7 Replies
And note that the logs I linked to still reflect the issue I was experiencing.
Did you press try again?
no
don't think that would resolve the root cause
I'm sorry but I don't understand what the issue here is. Where is the delay? The action was enqueued 5 seconds before it completed
There are logs that should be showing up that aren't. Here's another more recent example:
https://tapestry-stitch.gadget.app/edit/dev-kalen/logs?logql=%7Benvironment_id%3D%22468181%22%7D%20%7C%20json%20%7C%20level%3D~%22info%7Cwarn%7Cerror%22%20%7C%20backgroundActionId%3D%22job-XdzggWoBEXtPFG_VMtHHc%22&timeRange%5Binput%5D=Since%202025-06-16T15%3A35%3A25.028Z
It would be impossible for this action to have completed and returned the output that it returned without more logs:
https://tapestry-stitch.gadget.app/edit/dev-kalen/queues/job-XdzggWoBEXtPFG_VMtHHc
Should be logging this line on 372 for example:
https://tapestry-stitch.gadget.app/edit/dev-kalen/files/_actions/shopifySupplementalSync.mjs?startLineNumber=372&startColumn=0&endLineNumber=373&endColumn=0
When I run this in cli mode it works fine.
It feels like logs and perhaps response data is getting mixed between queue jobs.
@kalenjordan i think the logs for your actions are messed up because of the module-level variables that that action is using to store loggers
each time that helper function runs, it will change the top level value of the logger variable, with no guarantee that other simultaneous executions of that helper function are done yet
so one execution can change the logger to its own while the other execution is running, and the other execution will end up using a different logger than it started with
the logger instances are the bits that have the extra context associated with them like the
backgroundActionId , so if you use one action execution's logger within a different action execution, you will lose that contextaaaaaah brutal thanks for the catch.