Prevent more than one simultaneous episode move/rename?

Help & Support
#1

Sonarr version (exact version): Latest
Mono version (if Sonarr is not running on Windows): wut?
OS: Centos 7
Debug logs: not necessary?
Description of issue:

I have been having an issue for a long time, and I’ve finally come to suspect it may be caused due to the following:

I have most of my Plex media library on a cloud drive (Samba mounted to CentOS - I’m a bit of a nix-ophobe so forgive technical lingo inaccuracies), but when Sonarr attempts to move mutiple completed downloads over to this drive at once, it seems to be resulting in incomplete files on the other side. So I can later fix this (when I eventually end up frustrated at an episode stopping part way through) just by downloading the same episode, if it happens to still be available (super frustrating when it isn’t) and ensuring I don’t attempt to download another at the same time or it may happen again.

So evidently the problem is that Sonarr will start moving one episode to the cloud drive, then if SABnzbd ends up completing a new download before that move has finished, will attempt to initiate an additional parallel move to the same drive, and presumably that’s the point when the first move breaks, leaving an incomplete episode.

So hopefully I assume if I can find a way to prevent Sonarr from moving new files before the previous file has finished moving (or additionally after they’ve been picked up by Plex), this problem should be history and I’ll never have to face the annoyance of manually re-downloading the episode midway through watching it again. So, does anyone know of any way this can be achieved?

If this cannot be done, then I guess it’s a much needed feature for me. This issue has been plaguing me for ages and I’ve found it really hard to finally pinpoint what the cause is. I’ve even considered learning Python just to routinely test each episode is fully downloaded and delete the episode and tell Sonarr to try again if not.

#2

If you’re using Completed Download Handling Sonarr will only import one thing at a time.

If you’re using a script to tell Sonarr to import it’s possible that more than one could be executing.

Sonarr also checks when importing if a file wasn’t imported completely and will retry a couple of times before failing.

#3

Hm, I’ve been constantly ending up with shows that have downloaded seasons at a time (rather than as and when they’re released) being incomplete and breaking part way through watching certain episodes. Then if I delete the file and download the exact same release again, it works, so I’m not sure what else could be going on. I’ve verified that the files are being imported at a lower size than they should be… so unless SABnzbd has some bizarre issue where files sometimes download incompletely, I cannot see any other reason this is happening - and surely if Sonarr also checks the import completed successfully, it should cover issues on the SABnzbd side as well?

#4

Going to need to see trace logs of an import that fails to copy the full file, that’s the only way we’ll be able to see what Sonarr sees with enough detail.

If SAB only extracted half a file Sonarr would only import that half and think it’s complete (it compares the source file size to the destination file size), though I’ve never seen that behaviour with SAB

#5

Right, that’s the problem I’ve had with getting as far as I have in diagnosing this issue though, I never know the file import has failed until I try to watch the video and it fails, which is usually a good while after it has downloaded, and generally at that time I’m more interested in fixing it ASAP and getting to the end of the episode.

I’ll have to try and dedicate some time to spam-downloading a season of a random show to invoke the error myself so I can find the logs. Thanks for the help though, will try to do that ASAP and get back to you.

#6

Okay, I did it, replicated the issue, got the log, then found out that it was only an Info level log as Sonarr seems to have reset the option when I restarted it to stop it’s crazy unpausable import spree… so I have to do all that again now it seems. But a question: how do I post logs here with the character limit being as low as it is? Guess I’ll use Pastebin, but meh…

#7

Pastebin or any similar site is preferred yes :slight_smile:
Pretty much anywhere the raw textfile can be uploaded and viewed in its original form, so not inside a Google doc or something like that.

#8

OK, I did a proper test again, wasn’t able to replicate the issue on the season I just tested on, so tried the next season and managed to replicate it, but discovered some new factors that just make it totally confusing, and I think the Sonarr logs just show it’s working as it should… here is what I logged:

S09E01
CentOS (I access via CLI/SSH/whatever it's called) reports the local file is 188MB
CentOS reports the moved file is 188MB
Windows (accessing the drive as a network drive) reports the moved file is ~70MB, and the episode is 53 seconds long (at first I assume it was just Windows sucking at Unix stuff, however...)
In Plex, the file is 188MB, yet if I download it (Get Info > Download) the 188MB video breaks 53 seconds in, same thing happens when played directly in Plex (except weirder and harder to diagnose due to streaming)

So I went to the original “SABnzbd completed downloads” folder, found the file, copied it over to the storage box drive myself in the root directory, played it on Windows without downloading it, and lo and behold, the entire file plays. So there’s definitely an issue in copying/moving the file, but it seems like some weird kind of file system issue…? As a nix-ophobe, I’m clueless on what to think of that…

I copied the file myself via the command line a few times and it works every time. I then copied it to the Plex-watched folder to see if it would work, and it did, on everything. I still kind of feel like the only possible difference is that when Sonarr is doing it, lots of files are being moved over to the drive in quick succession.

Here’s the trace log to go over, but yeah, I’m starting to think this issue isn’t something Sonarr can address unless it is able to see what Windows sees when it looks at the files (surprisingly Windows is doing the best job in figuring out the files are incomplete on a CentOS managed drive, go figure), or test the actual ability to play the file fully: https://pastebin.com/tGSfmDkP

EDIT: To clarify, S09E01 is the episode to watch for, however the following files also exhibit the strange behaviour of the file sizes being suspiciously small according to Windows Explorer:
S09E02-S09E03 - 121MB (still a bit small for a double-episode? the rest of the series of single episodes is >150MB)
S09E04-S09E05 - 23MB
S09E06-S09E07 - 37MB
S09E08-S09E09 - 43MB
S09E14 - 18MB!

#9

No one has any ideas I guess? :disappointed:

#10 
18-8-24 15:01:56.3|Debug|DiskTransferService|Move [/home/shared/download/adventure.time.s09e01.dirfix.720p.hdtv.x264.1-w4f-xpost/d978f84270034710a3d1fb407d6678e9.mkv] > [/mnt/sd/VuServ/media/tv/Adventure Time/Season 9/Adventure Time - S09E01 - Orb.mkv]
18-8-24 15:01:56.3|Warn|ImportApprovedEpisodes|Couldn't import episode /home/shared/download/adventure.time.s09e01.dirfix.720p.hdtv.x264.1-w4f-xpost/d978f84270034710a3d1fb407d6678e9.mkv

[v2.0.0.5228] NzbDrone.Common.Disk.DestinationAlreadyExistsException: Destination /mnt/sd/VuServ/media/tv/Adventure Time/Season 9/Adventure Time - S09E01 - Orb.mkv already exists.
  at NzbDrone.Common.Disk.DiskTransferService.ClearTargetPath (System.String sourcePath, System.String targetPath, Boolean overwrite) <0x41d31720 + 0x000b7> in <filename unknown>:0 
  at NzbDrone.Common.Disk.DiskTransferService.TransferFile (System.String sourcePath, System.String targetPath, TransferMode mode, Boolean overwrite, DiskTransferVerificationMode verificationMode) <0x41d30730 + 0x0062b> in <filename unknown>:0 
  at NzbDrone.Common.Disk.DiskTransferService.TransferFile (System.String sourcePath, System.String targetPath, TransferMode mode, Boolean overwrite, Boolean verified) <0x41d306b0 + 0x0005b> in <filename unknown>:0 
  at NzbDrone.Core.MediaFiles.EpisodeFileMovingService.TransferFile (NzbDrone.Core.MediaFiles.EpisodeFile episodeFile, NzbDrone.Core.Tv.Series series, System.Collections.Generic.List`1 episodes, System.String destinationFilePath, TransferMode mode) <0x41d2ffb0 + 0x00403> in <filename unknown>:0 
  at NzbDrone.Core.MediaFiles.EpisodeFileMovingService.MoveEpisodeFile (NzbDrone.Core.MediaFiles.EpisodeFile episodeFile, NzbDrone.Core.Parser.Model.LocalEpisode localEpisode) <0x41d2f550 + 0x00117> in <filename unknown>:0 
  at NzbDrone.Core.MediaFiles.UpgradeMediaFileService.UpgradeEpisodeFile (NzbDrone.Core.MediaFiles.EpisodeFile episodeFile, NzbDrone.Core.Parser.Model.LocalEpisode localEpisode, Boolean copyOnly) <0x41d2e380 + 0x0068d> in <filename unknown>:0 
  at NzbDrone.Core.MediaFiles.EpisodeImport.ImportApprovedEpisodes.Import (System.Collections.Generic.List`1 decisions, Boolean newDownload, NzbDrone.Core.Download.DownloadClientItem downloadClientItem, ImportMode importMode) <0x41d29920 + 0x01409> in <filename unknown>:0

It looks like earlier the import failed and Sonarr didn’t handle the failure gracefully or something to that effect because Sonarr doesn’t know that file exists (it isn’t linked in Sonarr).

Unfortunately the logs don’t show the initial failure, just the subsequent attempts.

#11

Sooo when it tries to do it the second time, it sees a file already exists, then links it in Sonarr on the next scan (even though the file is only partially there)?

The logs should show everything from when I clicked the “scan all watched episodes in this season” button though. Is there anything more I can do to help resolve this or something?

#12

Yeah, next refresh (every 12 hours) would likely pick that up. At that point the import process could potentially try to “upgrade” the existing file, but it depends if the download is still sitting there and Sonarr sees it there still (for a season pack another successful download would mark the download as complete

Do you mean Search all monitored episodes in this season?

The logs don’t show everything in that one file, they only show the subsequent attempts to import, previous logs likely showed something, but those would have rolled over by now I think.

Really the only thing is the logs, namely from the original failed import to understand why it failed to import the first time (and didn’t clean up the failed import either). Not trivial given the automated nature of things, but it’s what we’ll need.

Moving away from Samba would probably be best, typically we recommend NFS for shares instead of Samba due to issues moving files to Samba shares (it’s the reason why we have the logic to check the file during import and compare the file size). Alternatively running Sonarr on Windows should handle any issues with Samba shares.

#13

Yes, I specifically cleared all the logs out and then ran that, hoping everything would be logged from that point.

Unfortunately my storage box provider doesn’t seem to support NFS at all (I think WebDAV is my only other choice for mounting and it sounds terrible). Not sure how I’d get Sonarr set up on my local system to manage the remote server but I guess I could give it a try. I’ll try to do another test and get to the logs before Sonarr discards them or whatever before that though…

What I have been doing now I’m aware of the underlying issue a bit more is comparing the file size reported via my Windows mount to the size Sonarr says the completed download should be, and if the real size is less, deleting it via Sonarr and auto-searching again, which consistently fixes it. But this still has the downside of needing me to manually get to it, by which time releases could have expired and such.

Would Sonarr not be able to do this using a checksum rather than a plain stat to retrieve the file size (which non-Windows systems seem to mis-report as being the expected size)?

#14

Okay, I was casually fixing episodes in a previously working series (which Sonarr must have since ‘upgraded’ into files which are incomplete), and then realised I could do a quick test by enabling trace logging, and triggering a search for two episodes in quick succession. I did it, managed to recreate the error on the episode, producing a 164MB file that should have been around 280MB, and isolated the part of the log, and managed to actually find some problematic-looking stuff (S01E20): https://pastebin.com/KnA6h6qF

From what I can tell, Sonarr tried to delete the episode, but it failed… no idea why specifically, but there are many different errors going on around there. Hopefully it’s more helpful in determining the root cause. It also seemed to have been doing some stuff with Episode 21 at the same time, but that one succeeded…

#15

The logs are busy because there are 4 requests to manually delete a different file at the same time.

What I see is Sonarr start the import process and attempt to hardlink the file to the destination, but it’s on a different mount, so it fails (which is expected)

18-8-29 14:42:42.4|Debug|EpisodeFileMovingService|Moving episode file: /home/shared/download/Adventure.Time.With.Finn.And.Jake.S01E20.720p.BluRay.x264-DEiMOS/Adventure.Time.With.Finn.And.Jake.S01E20.720p.BluRay.x264-DEiMOS.mkv to /mnt/sd/VuServ/media/tv/Adventure Time/Season 1/Adventure Time - S01E20 - Freak City.mkv
18-8-29 14:42:42.4|Debug|DiskTransferService|Move [/home/shared/download/Adventure.Time.With.Finn.And.Jake.S01E20.720p.BluRay.x264-DEiMOS/Adventure.Time.With.Finn.And.Jake.S01E20.720p.BluRay.x264-DEiMOS.mkv] > [/mnt/sd/VuServ/media/tv/Adventure Time/Season 1/Adventure Time - S01E20 - Freak City.mkv]
18-8-29 14:42:42.4|Trace|SymbolicLinkResolver|Checking path /mnt/sd/VuServ/media/tv/Adventure Time/Season 1/Adventure Time - S01E20 - Freak City.mkv for symlink returned error ENOENT, assuming it's not a symlink.
18-8-29 14:42:42.4|Trace|DiskTransferService|Attempting to move hardlinked backup.
18-8-29 14:42:42.4|Debug|DiskProvider|Hardlink '/home/shared/download/Adventure.Time.With.Finn.And.Jake.S01E20.720p.BluRay.x264-DEiMOS/Adventure.Time.With.Finn.And.Jake.S01E20.720p.BluRay.x264-DEiMOS.mkv' to '/home/shared/download/Adventure.Time.With.Finn.And.Jake.S01E20.720p.BluRay.x264-DEiMOS/Adventure.Time.With.Finn.And.Jake.S01E20.720p.BluRay.x264-DEiMOS.mkv.backup~' failed.

[v2.0.0.5228] System.InvalidOperationException: Operation not permitted ---> Mono.Unix.UnixIOException: Operation not permitted [EPERM].
  --- End of inner exception stack trace ---
  at Mono.Unix.UnixMarshal.ThrowExceptionForLastError () <0x41d32ed0 + 0x00013> in <filename unknown>:0
  at Mono.Unix.UnixMarshal.ThrowExceptionForLastErrorIf (Int32 retval) <0x41d32eb0 + 0x00013> in <filename unknown>:0
  at Mono.Unix.UnixFileSystemInfo.CreateLink (System.String path) <0x41d32bf0 + 0x0002b> in <filename unknown>:0
  at NzbDrone.Mono.Disk.DiskProvider.TryCreateHardLink (System.String source, System.String destination) <0x41d31d90 + 0x0005b> in <filename unknown>:0

Sonarr then copies the file, which succeeds:

18-8-29 14:42:42.7|Trace|DiskTransferService|Hardlink move failed, reverting to copy.
18-8-29 14:43:21.4|Trace|DiskTransferService|Copy succeeded, deleting source.

Finally Sonarr attempts to delete the original file, which fails:

18-8-29 14:43:21.4|Trace|DiskProviderBase|Deleting file: /home/shared/download/Adventure.Time.With.Finn.And.Jake.S01E20.720p.BluRay.x264-DEiMOS/Adventure.Time.With.Finn.And.Jake.S01E20.720p.BluRay.x264-DEiMOS.mkv
18-8-29 14:43:21.4|Warn|ImportApprovedEpisodes|Couldn't import episode /home/shared/download/Adventure.Time.With.Finn.And.Jake.S01E20.720p.BluRay.x264-DEiMOS/Adventure.Time.With.Finn.And.Jake.S01E20.720p.BluRay.x264-DEiMOS.mkv
 
[v2.0.0.5228] System.UnauthorizedAccessException: Access to the path "/home/(removed)/download/Adventure.Time.With.Finn.And.Jake.S01E20.720p.BluRay.x264-DEiMOS/Adventure.Time.With.Finn.And.Jake.S01E20.720p.BluRay.x264-DEiMOS.mkv" is denied.
  at System.IO.File.Delete (System.String path) <0x418bd210 + 0x00167> in <filename unknown>:0
  at NzbDrone.Common.Disk.DiskProviderBase.DeleteFile (System.String path) <0x41cd3780 + 0x0013f> in <filename unknown>:0
  at NzbDrone.Common.Disk.DiskTransferService.TryMoveFileTransactional (System.String sourcePath, System.String targetPath, Int64 originalSize, DiskTransferVerificationMode verificationMode) <0x41d31980 + 0x0038d> in <filename unknown>:0
  at NzbDrone.Common.Disk.DiskTransferService.TransferFile (System.String sourcePath, System.String targetPath, TransferMode mode, Boolean overwrite, DiskTransferVerificationMode verificationMode) <0x41d30730 + 0x00a37> in <filename unknown>:0
  at NzbDrone.Common.Disk.DiskTransferService.TransferFile (System.String sourcePath, System.String targetPath, TransferMode mode, Boolean overwrite, Boolean verified) <0x41d306b0 + 0x0005b> in <filename unknown>:0
  at NzbDrone.Core.MediaFiles.EpisodeFileMovingService.TransferFile (NzbDrone.Core.MediaFiles.EpisodeFile episodeFile, NzbDrone.Core.Tv.Series series, System.Collections.Generic.List`1 episodes, System.String destinationFilePath, TransferMode mode) <0x41d2ffb0 + 0x00403> in <filename unknown>:0
  at NzbDrone.Core.MediaFiles.EpisodeFileMovingService.MoveEpisodeFile (NzbDrone.Core.MediaFiles.EpisodeFile episodeFile, NzbDrone.Core.Parser.Model.LocalEpisode localEpisode) <0x41d2f550 + 0x00117> in <filename unknown>:0
  at NzbDrone.Core.MediaFiles.UpgradeMediaFileService.UpgradeEpisodeFile (NzbDrone.Core.MediaFiles.EpisodeFile episodeFile, NzbDrone.Core.Parser.Model.LocalEpisode localEpisode, Boolean copyOnly) <0x41d2e380 + 0x0068d> in <filename unknown>:0
  at NzbDrone.Core.MediaFiles.EpisodeImport.ImportApprovedEpisodes.Import (System.Collections.Generic.List`1 decisions, Boolean newDownload, NzbDrone.Core.Download.DownloadClientItem downloadClientItem, ImportMode importMode) <0x41d29920 + 0x01409> in <filename unknown>:0

The copy is successful in Sonarr’s eyes (comparing the size of the source and destination), otherwise it would have logged that it failed to completely transfer the file and that it was retrying (until it ran out of retries).

Best I can tell the file is corrupt before Sonarr imports it, or the destination file size is correct when checked and later fails to upload completely, resulting in the episode being cutoff.

This doesn’t appear to have anything to do with multiple imports, the logs show only one in progress, but something else, outside of Sonarr.

#16

As I pointed out earlier, stat-ing the file in CentOS will report that the file is its full size, yet viewing it in Windows shows that it actually isn’t. So the issue appears to be a weird CentOS/linux/? issue where if file is supposed to be a certain size on the mounted Samba share (I guess there is some hidden info showing what the file size should be), it will just report that size even if all those bytes aren’t actually accessible/written in the file, which is why I mentioned validating it by checksum on either end: surely then at least it would have to actually be fully readable (and not corrupt) as well as being “reportedly” the correct size in order for the checksum to be valid.

But this issue also only ever happens if there are multiple imports/downloads going in quick succession. It has never happened after just trying to get a single episode, as far as I’m aware, only if Sonarr automatically gets multiple files in a season, or I manually trigger multiple searches at once. Forcing a delay between different file imports would presumably fix it (just as I have to wait a couple of minutes between making Sonarr search for each episode if I manually do it, or it will have the exact same issue half of the time). The source file is definitely never corrupt so long as SABnzbd successfully downloaded it.

I think either an option to have a checksum based verification rather than a size based verification, or an option to add a delay between successive imports would allow me to solve the issue (or anyone else trying to use Samba shares that has this problem, I’m presuming), but I understand it may be a bit too specific to ask for, so I imagine my only option would be to figure out how to write some sort of script to do exactly what I’m doing to fix them manually, which will surely not be easy.

#17

While we may use additional information to determine if a file copied successfully in the future a checksum of the file would require the entire file to be read, which would be a problem for cloud storage and double the bandwidth required to import it.

An option to slow down the imports isn’t something we’re going to consider and overall “fixing” this is Sonarr is a bandaid given the issue is with the filesystem and importing over Samba/CIFS is a known issue that we try to deal with already.

At the moment I can’t think of a good way in Sonarr to work around this issue, but I’d recommend focusing on the underlying problem of a file not reporting its correct size or move away from Samba/CIFS.

#18

I think I managed to find some sort of temporary fix, hopefully I don’t jinx it. Ironically I found the fix from another post on these forums: Strange failures on CIFS mounts - Solution

Now files copy slow as hell, but Sonarr at some point upgraded an entire season of a show and all the files were imported without any incomplete files.

#19

This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.