Sonarr not handling EXDEV signal properly

[LanderN]

More details and discussion can be found here: https://github.com/trapexit/mergerfs/issues/381

[Taloth]

afaik Mono handles EXDEV and falls back to copy followed by a delete. (https://github.com/mono/mono/blob/f704d56c378b28e252572db4730a6e13edc14aa0/mono/metadata/w32file-unix.c#L2692-L2706)
In write_file it effectively does a buffer read from one file, writes to the other, rinse and repeat.

My guess is that the copy action fails, for whatever reason.
There are like two dozen places where that 25 error can come from.

You should first check which version of mono you're running.

PS: it feels like jumping to conclusions about the EXDEV signal, especially since the error points at something totally different.

[trapexit]

I agree that the error reports a SEEK problem but the symptoms (and work around) fit the standard issue of mishandling of EXDEV.

I saw that that move call was supposed to handle EXDEV but it went away when my software was setup such that that error would not be returned.

While it doesn't immediately appear that way I have seen EXDEV handled in such a way that it resulted in another error being thrown (certain SMB clients for instance).

[trapexit]

Perhaps it's an issue with CopyFile?

Looks like there is a way to turn on higher level of debugging?

https://github.com/mono/mono/blob/f704d56c378b28e252572db4730a6e13edc14aa0/mono/metadata/w32file-unix.c#L2755

Perhaps that'd help in tracking down the issue?

[Taloth]

Possibly, i was going to say:

So by configuring category.create=ff mergerfs doesn't return EXDEV, but it feels like it's simply changing the behavior of mergerfs in such a way that the move succeeds. Thus masking the actual problem.

A test case would be to use a simple c# test application that attempts a File.Copy(...), see if the 25 error occurs there as well. (I'm assuming for a second that mono does the File.Copy the same as it's fallback copy for EXDEV, except for the subsequent delete operation).

[Taloth]

While i was typing this: https://gist.github.com/Taloth/accea491afc085611191be442a6e5be5

Save as filecopy-test.cs
Cmd to compile on target machine (assuming mono dev/full is installed): mcs -debug filecopy-test.cs
Cmd to run:
mono --debug filecopy-test.exe move {src} {dest} or
mono --debug filecopy-test.exe copy {src} {dest}.

[trapexit]

It seems to be working fine. Unfortunately I don't know enough about @LanderN 's setup or Sonarr's usage to test further.

Ideally @LanderN would use the above tool to move the file the same way Sonarr is.

[trapexit]

Maybe if Sonarr is run with debugging enabled there would be more information to go on without needing @LanderN to replicate the situation precisely. Move is returning what Copy reports as an error without being able to know where exactly it came from. However, CopyFile doesn't seem to have any explicit seeks. Is error 25 indeed ERROR_SEEK?

[Taloth]

Yes, I posted the code for @LanderN to test with.
Running Sonarr itself in debug mode doesn't matter, coz the logging you mentioned is deep in mono and thus needs mono trace env vars, I'd have to dive in to get the exact env var, it's been a while. And running mono trace on Sonarr itself is not advisable since the amount of noise that it would no doubtly cause. So a repro using a small tool is the first step.

mono tries translating errors, there are no guarantees that the error code is correct, could be unix errno 25 ENOTTY (Inappropriate ioctl for device), but regardless of what the exact error is, it must be triggered somewhere in that mono subsystem.

Does mergerfs have a log function to dump all the IO commands?

[LanderN]

Output of the tool with move:

An unexpected error occurred:
System.IO.IOException: Win32 IO returned 25. Path:
  at System.IO.File.Move (System.String sourceFileName, System.String destFileName) <0x7efcfb95a5c0 + 0x002f0> in <filename unknown>:0
  at Program.Main (System.String[] args) [0x000f5] in /home/lander/sonarr-mergerfs-issue/filecopy-test.cs:46

Output of the tool with copy:

An unexpected error occurred:
System.IO.IOException: Win32 IO returned 25. Path: /mnt/hdd3/Downloads/Complete/Some.TV.Series/Some.Episode.Of.A.TV.Series.S1E1.mkv" or "/srv/samba/media/Series/Some_TV_Series/Season_1/Some.Episode.Of.A.TV.Series.S1E1.mkv
  at System.IO.File.Copy (System.String sourceFileName, System.String destFileName, Boolean overwrite) <0x7f707ad59a80 + 0x004d1> in <filename unknown>:0
  at System.IO.File.Copy (System.String sourceFileName, System.String destFileName) <0x7f707ad59a60 + 0x00013> in <filename unknown>:0
  at Program.Main (System.String[] args) [0x00110] in /home/lander/sonarr-mergerfs-issue/filecopy-test.cs:49

This is with category.create=epmfs

[trapexit]

No. A filesystem generating logs isn't really ideal. It can be strace'd though to see what it's vaguely doing and any errors those calls may be triggering.

strace -p <mergerfspid> -f -o /tmp/mergerfs.strace

Might be easier to strace Sonarr though.

[trapexit]

Interesting. Try the same but prepend strace -f -o /tmp/trace to the command and attach the file here.

[LanderN]

Here are the traces:

trace with copy
trace with move

[trapexit]

EINVAL...

Strange. Maybe this is a FUSE/mergerfs issue. Not sure why yet though. Let me dig deeper. I'm not returning EINVAL explicitly. Might need mergerfs straces.

open("/srv/samba/media/Series/The_Walking_Dead/Season_7/The_Walking_Dead.S07E16.The_First_Day_of_the_Rest_of_Your_Life.HDTV-720p_Proper-KILLERS.mkv2", O_WRONLY|O_CREAT|O_EXCL, 0100777) = -1 EINVAL (Invalid argument)

[trapexit]

If you use mv to do the same thing... does it work?

[LanderN]

As a matter of fact, it doesn't! Weird that I only noticed this issue today...
mv: cannot create regular file '/srv/samba/media/Series/The_Walking_Dead/Season_7/The_Walking_Dead.S07E16.The_First_Day_of_the_Rest_of_Your_Life.HDTV-720p_Proper-KILLERS.mkv2': Invalid argument

I guess we don't have sonarr/mono to blame then obviously...

[trapexit]

Strange. Sorry to waste your time @Taloth

[Taloth]

@trapexit Wasn't a waste, happy to help.

[trapexit]

For those interested: it looks like ntfs-3g returns EINVAL when receiving an ioctl cmd it doesn't understand. mergerfs ignores certain errors for certain commands (copying of file attributes and extended attributes) when trying to copy paths between drives but EINVAL is not one of them (ENOTSUP, ENOTTY are ignored).

I had thought people had used ntfs-3g with mergerfs before so it didn't cross my mind to check for filesystem incompatibilities.