Failed download handling issue from Sonarr

[kevindd992002]

Hmm, interesting.

Yeah, shypike what are your ideas here?

[shypike]

I'll have a look at improviseren logging.
Very likely a timing issue that only occurs in some situations.

[safihre]

Don't think it's a timing issue looking at his logs, there are minutes between sabnzbd declaring the job failed and Sonarr sending the delete request..

[shypike]

So what is going on?
Is the job already gone before deletion?
Is the job gone after Sonarr sends the deletion command?
Does Sonarr send the wrong nzo_id code?

[safihre]

Sonarr sends the right code (see log), the job is there, but the problem is that it stays there.
Even though the Delete command is send (see his screenshot that still has the 1 Failed download in it).

The download gets added 3 times, fails the first 2 times. Sonarr sends 2 delete commands. Only 1 seems to have executed, causing the history to show 1 failed and the final succeeded download.

[kevindd992002]

Exactly what safihre said.

[kevindd992002]

Shypike, do we have any progress on this?

[kevindd992002]

Just a gentle follow-up on this please?

[safihre]

Unfortunately we have no clue and can't reproduce it on our systems and with other users..
But we really should add the extra Debug logging on a delete command.

[kevindd992002]

Ok. Yeah, how soon can you implement that though? I would be happy to recreate the issue on my end when a more verbose debugging is incorporate in Sab. This issue is something that happens very often (not consistent) that makes it already annoying.

[shypike]

From what I have been able to reconstruct from the logging posted some time ago is this.
Sonarr tries to delete a job while it's being post-processed.
That:
1) leads to an (otherwise innocent) log entry and an error message
2) results in a job that is not deleted, because the actual post processing isn't aware of the delete command

Any idea why Sonarr would want to delete a job that is still being actively post-processed?

[kevindd992002]

These jobs aren't completed at all so I'm not sure if post-processing even started? Sonarr tries to deleted these jobs because they failed for whatever reason (abort due to incomplete files, missing par files, etc.).

[shypike]

Yes, but I clearly see that the delete command comes
during the post-processing phase.
It could still be a race-condition.
About a half a second before PP ends, the status gets its final value.
So maybe that explains what happens.

I will look into counter-measures for this issue.
Removing the error message and log is the easy part.
What you want is that the item is still deleted.
In principle the running PP item cannot be stopped,
but this is an edge case, I think.

[kevindd992002]

Oh ok. I thought PP only happens for completed jobs? Why would it ran PP for incomplete jobs?

[shypike]

Often failure can only be concluded by running the par2 verification.
That's done by post-processing.
Looking at the code, the delete action contains some awkward code.
I'm working on a better solution that will prevent this issue.