Outputting empty files - Githubissues

wormoworm commented 3 years ago

Since updating to the latest version (1.29.2) on my Synology NAS yesterday, rar2fs has stopped working for me. The symptoms of the problem are as follows:

I'm able to mount a directory in the usual way using /opt/bin/rar2fs --seek-length=1 -o allow_other /volume1/source /volume1/dest. No errors when running this command.
I'm able to browse the directory structure in /volume1/dest just fine, and listing files inside directories created from multi-part rar archives shows me the files in the archive (names and file lengths appear to be correct).
When reading a file (either in Plex, a Windows application over the network, or even just raw via xxd), I get only zeroes.

On the previous version (v1.27.2 I believe, but I'm not 100% sure!) reading files from inside archives worked fine, and in fact this formed the basis for my media consumption for well over a year with very few hitches, if any.

Some info about the system rar2fs is running on:

uname -a
Linux Asgard 4.4.59+ #25426 SMP PREEMPT Tue May 12 04:54:55 CST 2020 x86_64 GNU/Linux synology_apollolake_918+

rar2fs --version
rar2fs v1.29.2 (DLL version 8)    Copyright (C) 2009 Hans Beckerus
This program comes with ABSOLUTELY NO WARRANTY.
This is free software, and you are welcome to redistribute it under
certain conditions; see <http://www.gnu.org/licenses/> for details.
FUSE library version: 2.9.9
fusermount version: 2.9.4
using FUSE kernel interface version 7.19

ldd $(which rarf2s)
linux-vdso.so.1 (0x00007ffce5a9b000)
        libfuse.so.2 => /opt/lib/libfuse.so.2 (0x00007f8e031c9000)
        libunrar.so => /opt/lib/libunrar.so (0x00007f8e03170000)
        libiconv.so.2 => /opt/lib/libiconv.so.2 (0x00007f8e0308a000)
        libdl.so.2 => /opt/lib/libdl.so.2 (0x00007f8e03085000)
        librt.so.1 => /opt/lib/librt.so.1 (0x00007f8e0307b000)
        libstdc++.so.6 => /opt/lib/libstdc++.so.6 (0x00007f8e02ef1000)
        libm.so.6 => /opt/lib/libm.so.6 (0x00007f8e02d5c000)
        libgcc_s.so.1 => /opt/lib/libgcc_s.so.1 (0x00007f8e02b45000)
        libpthread.so.0 => /opt/lib/libpthread.so.0 (0x00007f8e02927000)
        libc.so.6 => /opt/lib/libc.so.6 (0x00007f8e02577000)
        /opt/lib/ld-linux-x86-64.so.2 (0x000055a252637000)

None of my rar'ed MKVs are opening correctly, here are the details of one, a typical multi-part "store-only" rar:

unrar lt its.always.sunny.in.philadelphia.s05e02.720p.bluray.x264-sinners.rar
UNRAR 5.91 freeware      Copyright (c) 1993-2020 Alexander Roshal
Archive: its.always.sunny.in.philadelphia.s05e02.720p.bluray.x264-sinners.rar
Details: RAR 4, volume, recovery record

        Name: Its.Always.Sunny.In.Philadelphia.S05E02.720p.BluRay.x264-SiNNERS.mkv
        Type: File
        Size: 938745335
 Packed size: 49505873
       Ratio: -->
       mtime: 2010-09-11 12:25:57,187500000
  Attributes: ..A....
  Pack-CRC32: B7DECC42
     Host OS: Windows
 Compression: RAR 1.5(v20) -m0 -md=4M

Steps I've tried so far:

Restarting the NAS :)
Uninstalling only rar2fs and then reinstalling (using opkg package manager).
Uninstalling rar2fs, unrar and libfuse and the reinstalling unrar followed by rar2fs (rar2fs install pulls in libfuse as well).
Experimenting with various options listed by rar2fs --help, such as --seek-length=0 / 1 / 2, umask=000 / 777 / 022 and default_permissions.
Running rar2fs in foreground / debug mode using -f / -d. In debug mode I see a lot of activity when trying to play the above mkv in VLC on my PC, but looking at the output, there are no obvious warnings or errors.
I've started to look into pulling the source and compiling rar2fs myself, but I'm running into some tooling issues (e.g. autoconf missing) on the NAS. I will keep trying though.

Help me hasse69, you're my only hope!

hasse69 commented 3 years ago

Thanks for the well authored issue report.

Before we continue looking into this, my experience with no output is very often related to incompatible version of libunrar being used. What makes me a bit suspicious is the output from ldd.

libunrar.so => /opt/lib/libunrar.so (0x00007f8e03170000)

The later versions of rar2fs does not use dynamic linking by default for that exact reason. Are you 100% sure the libunrar you have in /opt/lib actually matches the source you used for compiling rar2fs v1.29.2?

wormoworm commented 3 years ago

Thanks for the fast reply! One thing to mention is that I did not succeed in compiling v1.29.2 from source (architecture / tools issues - I'm sure I can solve them, but it will take a while!) The 1.29.2 I'm running at the moment was simply installed using opkg install rar2fs, and it's pulling its packages from http://bin.entware.net/x64-k3.2/. As a result I'm not really sure if the version of libunrar I have at /opt/lib/libunrar matches the package I installed via opkg. I can confirm that removing libunrar using opkg remove libunrar removes it from /opt/lib, and installing it again with opkg install libunrar places it there again.

hasse69 commented 3 years ago

The problem is that upstream libunrar does not properly tag its .so versions which makes distros really hard to maintain properly. When you build rar2fs you need to point it to the source code of libunrar and if that source is not also exactly what is installed then there is a huge risk there are going to become incompatibilities. I am not sure what built the opkg but there is a possibility that latest rar2fs was built towards a version of libunrar that is not yet released as an opkg.

I have tried to make distro maintainers aware of this problem and by default rar2fs links statically to whatever it was built against. Whatever/whoever built this opkg either used a very old version of libunrar that did not support the static archive or they forced dynamic linking by overriding the default.

Note that this it is still a qualified guess and I cannot of course say for sure this the root cause of the problem you currently experiencing.

hasse69 commented 3 years ago

I checked x64-k3.2 and if libunrar is pulled from the same place as rar2fs then it is this version

libunrar_5.9.4-1_x64-3.2.ipk

So question now is: was that really the version used when compiling rar2fs?

Unfortunately there is no easy way to know for sure unless we can contact whoever compiled this binary package. The best approach is to compile it yourself, then we would know for sure. I can possibly guide you if there are any questions that arise while trying such. I am a bit reluctant to start troubleshooting this issue unless we can eliminate this current suspicion of mine.

hasse69 commented 3 years ago

Also if you can find out what exact version of libunrar was used in the build you can limit your own efforts to only build that version of libunrar (very simple) and replace what you currently have installed.

And if you could do

$ file $(which rarf2s)

then I might already have a binary prepared that you could try

wormoworm commented 3 years ago

Here's the output from file:

file $(which rar2fs)
/opt/bin/rar2fs: ELF 64-bit LSB executable, x86-64, version 1 (SYSV), dynamically linked, interpreter /opt/lib/ld-linux-x86-64.so.2, for GNU/Linux 3.2.0, stripped

I had some success late last night however: It turns out that running

rar2fs --seek-length=1 -o allow_other /volume1/Films /volume1/unrar/films

works fine (files are not just zeroes and media plays in Plex), whereas

/opt/bin/rar2fs --seek-length=1 -o allow_other /volume1/Films /volume1/unrar/films

does not work (zeroes in files).

I feel a bit stupid for not checking this before - I assumed that calling /opt/bin/rar2fs was the same as simply calling rar2fs, but it's clearly not! I have verified that I only have one copy of rar2fs installed on the NAS, so it's not a case of having an old version lying around somewhere.

Would you expect /opt/bin/rar2fs to work? Or do you recommend simply running rar2fs and ensuring /opt/bin is in $PATH?

hasse69 commented 3 years ago

It does not really make sense. How you invoke the command using an explicit path or not makes no difference if they point to the same binary. Can you please check

ldd $(which rar2fs) ldd /opt/bin/rar2fs

And the same combination for —version.

$(which rar2fs) —version rar2fs —version /opt/bin/rar2fs —version

I still suspect you have two different versions of rar2fs installed.

EDIT: Removed one invocation of ldd above since it would not work, my bad.

wormoworm commented 3 years ago

Sorry for the delay getting back to you, here you go:

ldd $(which rar2fs)
linux-vdso.so.1 (0x00007ffdae3d4000)
libfuse.so.2 => /opt/lib/libfuse.so.2 (0x00007f049f9c5000)
libunrar.so => /opt/lib/libunrar.so (0x00007f049f96a000)
libiconv.so.2 => /opt/lib/libiconv.so.2 (0x00007f049f884000)
libdl.so.2 => /opt/lib/libdl.so.2 (0x00007f049f87f000)
librt.so.1 => /opt/lib/librt.so.1 (0x00007f049f875000)
libstdc++.so.6 => /opt/lib/libstdc++.so.6 (0x00007f049f6eb000)
libm.so.6 => /opt/lib/libm.so.6 (0x00007f049f556000)
libgcc_s.so.1 => /opt/lib/libgcc_s.so.1 (0x00007f049f33f000)
libpthread.so.0 => /opt/lib/libpthread.so.0 (0x00007f049f121000)
libc.so.6 => /opt/lib/libc.so.6 (0x00007f049ed71000)
/opt/lib/ld-linux-x86-64.so.2 (0x0000559974951000)

ldd /opt/bin/rar2fs
linux-vdso.so.1 (0x00007fff9ff93000)
libfuse.so.2 => /opt/lib/libfuse.so.2 (0x00007f6f527ba000)
libunrar.so => /opt/lib/libunrar.so (0x00007f6f5275f000)
libiconv.so.2 => /opt/lib/libiconv.so.2 (0x00007f6f52679000)
libdl.so.2 => /opt/lib/libdl.so.2 (0x00007f6f52674000)
librt.so.1 => /opt/lib/librt.so.1 (0x00007f6f5266a000)
libstdc++.so.6 => /opt/lib/libstdc++.so.6 (0x00007f6f524e0000)
libm.so.6 => /opt/lib/libm.so.6 (0x00007f6f5234b000)
libgcc_s.so.1 => /opt/lib/libgcc_s.so.1 (0x00007f6f52134000)
libpthread.so.0 => /opt/lib/libpthread.so.0 (0x00007f6f51f16000)
libc.so.6 => /opt/lib/libc.so.6 (0x00007f6f51b66000)
/opt/lib/ld-linux-x86-64.so.2 (0x0000559c384d3000)

$(which rar2fs) --version
rar2fs v1.29.2 (DLL version 8)    Copyright (C) 2009 Hans Beckerus
This program comes with ABSOLUTELY NO WARRANTY.
This is free software, and you are welcome to redistribute it under
certain conditions; see <http://www.gnu.org/licenses/> for details.
FUSE library version: 2.9.9
fusermount version: 2.9.4
using FUSE kernel interface version 7.19

rar2fs --version
rar2fs v1.29.2 (DLL version 8)    Copyright (C) 2009 Hans Beckerus
This program comes with ABSOLUTELY NO WARRANTY.
This is free software, and you are welcome to redistribute it under
certain conditions; see <http://www.gnu.org/licenses/> for details.
FUSE library version: 2.9.9
fusermount version: 2.9.4
using FUSE kernel interface version 7.19

/opt/bin/rar2fs --version
rar2fs v1.29.2 (DLL version 8)    Copyright (C) 2009 Hans Beckerus
This program comes with ABSOLUTELY NO WARRANTY.
This is free software, and you are welcome to redistribute it under
certain conditions; see <http://www.gnu.org/licenses/> for details.
FUSE library version: 2.9.9
fusermount version: 2.9.4
using FUSE kernel interface version 7.19

I've also included these for good measure:

which rar2fs
/opt/bin/rar2fs

md5sum $(which rar2fs)
c53c6071dea2095b3351a5ca59cc0647  /opt/bin/rar2fs

md5sum /opt/bin/rar2fs
c53c6071dea2095b3351a5ca59cc0647  /opt/bin/rar2fs

Looks to me as if the version are all the same, but somehow the linked libraries are not? I'm not sure what the hex values in the output of ldd represent - are they hashes of some kind?

hasse69 commented 3 years ago

I'm not sure what the hex values in the output of ldd represent - are they hashes of some kind?

No they are not, that is the virtual address to which the dynamic library has been loaded. it will change over time so nothing is wrong, the same libraries are used.

I cannot really explain what is going on here. What I can say is that it has nothing to do with rar2fs. It is your OS that handles the run-time linker. Can you please check if you might be having multiple instances of libunrar.so?

# find / -name libunrar.so

Since as you describe it does not work if you invoke only rar2fs and rely on your PATH environment but it works if you explicitly point it out using an absolute path it must mean that something becomes different in the two cases.

There is another way we can try to look at what happens using strace. Try these two variants:

# strace /opt/bin/rar2fs
# strace rar2fs

Both of these commands will generate some important trace output on your terminal. Please attach the output, preferably in two plain text files.

hasse69 commented 3 years ago

Any news here or should we close this issue?

wormoworm commented 3 years ago

Hi, sorry for not getting back to you. Here's the results of find (excluding the data-only volume /volume1 - only media files, nothing else):

find / -path /volume1 -prune -false -o -name libunrar.so
/usr/lib/libunrar.so
/opt/lib/libunrar.so

So it seems there are two copies, one installed with rar2fs (/opt1), and one installed as part of Synology's distro (/usr). The md5sums of these are different:

md5sum /opt/lib/libunrar.so
241a747b65c644bd28cfdbf1b38ea985  /opt/lib/libunrar.so

md5sum /usr/lib/libunrar.so
8e595c656f934e84b9646cee3c09084b  /usr/lib/libunrar.so

I'm guessing this is causing the issue, and the version of rar2fs that I installed using opkg install rar2fs uses dynamic linking, so it's pulling in the libunrar.so from the Synology side of things.

strace outputs for each rar2fs you requested are attached here: strace-opt-bin-rar2fs.txt strace-rar2fs.txt

Thanks

hasse69 commented 3 years ago

Yes, you could try to rename the one in /usr/lib but I do not think it will help much to be honest. According to the strace output both invocation variants load the same version of libunrar.so

strace rar2fs
execve("/opt/bin/rar2fs", ["rar2fs"], 0x7ffd409837b0 /* 20 vars */) = 0
...
openat(AT_FDCWD, "/opt/lib/libunrar.so", O_RDONLY|O_CLOEXEC) = 3
...

strace /opt/bin/rar2fs
execve("/opt/bin/rar2fs", ["/opt/bin/rar2fs"], 0x7fffa98e8db0 /* 20 vars */) = 0
...
openat(AT_FDCWD, "/opt/lib/libunrar.so", O_RDONLY|O_CLOEXEC) = 3
...

The issue is most likely not with libunrar.so but something else.

hasse69 commented 3 years ago

When you say no files contents are displayed (only zeros), does that apply to files only inside RAR archives or any files below the mount point? To me this starts to point towards some permission issue even though I cannot explain why it would make a difference in what way you invoke a binary.

hasse69 commented 3 years ago

Also try to mount using the -d flag so that we can see what FUSE is actually doing when you try to read a file using e.g. hexdump -C -n 64 <file> or some other tool. I am also a bit suspicious to if the read requests are actually reaching the file system as intended or data is read from e.g. the page cache.

You should see something similar like this

unique: 163, opcode: OPEN (14), nodeid: 22, insize: 48, pid: 8814
open flags: 0x8000 <filename>
   open[139783670140112] flags: 0x8000 <filename>
   unique: 163, success, outsize: 32
unique: 164, opcode: FLUSH (25), nodeid: 22, insize: 64, pid: 8814
flush[139783670140112]
   unique: 164, success, outsize: 16
unique: 165, opcode: READ (15), nodeid: 22, insize: 80, pid: 8814
read[139783670140112] 16384 bytes from 0 flags: 0x8000
   read[139783670140112] 16384 bytes from 0
   unique: 165, success, outsize: 16400
unique: 166, opcode: FLUSH (25), nodeid: 22, insize: 64, pid: 8814
flush[139783670140112]
   unique: 166, success, outsize: 16
unique: 167, opcode: RELEASE (18), nodeid: 22, insize: 64, pid: 0
release[139783670140112] flags: 0x8000
   unique: 167, success, outsize: 16

hasse69 commented 3 years ago

Any updates here?

hasse69 commented 3 years ago

Closing this due to inactivity.

hasse69 / rar2fs

Outputting empty files #152

Some info about the system rar2fs is running on:

Steps I've tried so far: