FreeBSD Question


#1

I’ve been playing around with FreeBSD to move away from my Debian install and I have things working very well.

The one odd thing is that I have 1.45 mount on FreeBSD and if I go to play a file or even run a media info, I get:

2019/02/08 11:43:31 ERROR : TV/Dexter/Dexter.S05E01.mkv: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes
2019/02/08 11:43:31 ERROR : TV/Dexter/Dexter.S05E01.mkv: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes
2019/02/08 11:43:31 ERROR : TV/Dexter/Dexter.S05E01.mkv: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes
2019/02/08 11:43:31 ERROR : TV/Dexter/Dexter.S05E01.mkv: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes

I’m using my same mount command as before so not sure why it would be asking to change the file size.

 /usr/bin/rclone mount gcrypt: /GD --allow-other --buffer-size 256M --dir-cache-time 72h --drive-chunk-size 32M --log-level INFO --log-file /tmp/rclone.log --timeout 1h --umask 002 --vfs-read-chunk-size 128M --vfs-read-chunk-size-limit off --uid 1001 --gid 1001 --daemon

I am not sure why it is asking for write access.


#2

That log kind of indicates it is running the Truncate callback which is weird and not something I’d expect it to do for opening something read only.

Note that I’m not surprised there are differences between linux and freebsd - what bits of the FUSE filesystem implemented by rclone mount get called is very much up to the kernel.

Could you make a log with -vv and I’ll take a look.


#3

Here is the log.

Seems like it opens:

2019/02/08 12:30:12 DEBUG : Radarr_Movies/Unsane (2018)/Unsane (2018).mkv: Open: flags=O_WRONLY
2019/02/08 12:30:12 DEBUG : Radarr_Movies/Unsane (2018)/Unsane (2018).mkv: >Open: fd=Radarr_Movies/Unsane (2018)/Unsane (2018).mkv (w), err=<nil>
2019/02/08 12:30:12 ERROR : Radarr_Movies/Unsane (2018)/Unsane (2018).mkv: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes
2019/02/08 12:30:12 DEBUG : Radarr_Movies/Unsane (2018)/Unsane (2018).mkv: >Setattr: err=operation not permitted
2019/02/08 12:30:12 DEBUG : Radarr_Movies/Unsane (2018)/Unsane (2018).mkv: Setattr: a=Setattr [ID=0x3c Node=0x4 Uid=0 Gid=0 Pid=1535] size=25938409160 handle=INVALID-0x0
2019/02/08 12:30:12 DEBUG : Radarr_Movies/Unsane (2018)/Unsane (2018).mkv: Truncating file
2019/02/08 12:30:12 DEBUG : Radarr_Movies/Unsane (2018)/Unsane (2018).mkv: Open: flags=O_WRONLY
2019/02/08 12:30:12 DEBUG : Radarr_Movies/Unsane (2018)/Unsane (2018).mkv: >Open: fd=Radarr_Movies/Unsane (2018)/Unsane (2018).mkv (w), err=<nil>
2019/02/08 12:30:12 ERROR : Radarr_Movies/Unsane (2018)/Unsane (2018).mkv: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes
2019/02/08 12:30:12 DEBUG : Radarr_Movies/Unsane (2018)/Unsane (2018).mkv: >Setattr: err=operation not permitted

Which seems to be the wrong flag to open it with.


#4

Yes that looks very wrong!

Can you try an experiment in python…

If you do this at the python prompt replacing “/tmp/z” with a path to a file, does it do the same thing? Does the log from the mount look sensible?

>>> f = open("/tmp/z", "r")
>>> f.read(1)
'#'
>>> f.close()

Could you also try strace-ing the program which is doing the mediainfo or playing? It would be useful to see what system calls it is calling and see whether they match up with what rclone is receiving!


#5

So in python, it looks fine:

2019/02/08 17:55:09 DEBUG : TV/Dexter/Dexter.S01E01.mkv: Open: flags=OpenReadOnly
2019/02/08 17:55:09 DEBUG : TV/Dexter/Dexter.S01E01.mkv: Open: flags=O_RDONLY

strace seems to not be ported to amd64 on Freebsd so I’ll have to dig a bit and see on that.

I get the same set of errors when I play a file in Plex as well so doesn’t seem to be just mediainfo on FreeBsd that is problematic.


#6

That is good.

I think truss is the BSD equivalent of strace.


#7

Here is the truss log.

Which is a bit beyond me so I didn’t see anything that jumps out other than it seems for whatever reason it opens the file to write rather than read so maybe a fuse bug on FreeBSD.


#8

That is what I wanted to check, but I don’t see any opens in that log?


#9

Ok. I redid my test and captured the truss from when I first mounted it.

I just changed into the directory and mediainfo’ed the file and stopped the rclone process.


#10

I think that is a truss of the rclone process isn’t it? Can you do the medainfo process?


#11

Ah, ok. I misunderstood.

That looks like it opens it read only in that log:

|open("Unsane (2018).mkv",O_RDONLY,0666)|| = 3 (0x3)|
|---|---|---|
|open("Unsane (2018).mkv",O_RDONLY,0666)|| = 3 (0x3)|
|open("Unsane (2018).mkv",O_RDONLY,0666)|| = 4 (0x4)|


#12

Yes, read only.

So where did the call to Truncate come from and the opening with Write :confused:

Can you try compiling cmount for FreeBSD. If you run go build -tags cmount from the root of the rclone source directory then you’ll make an rclone with cmount capabilites (you’ll need the fuse dev package and the fuse library and a C compiler installed).

Can you try that (just use rclone cmount instead of rclone mount) and see if it has the same problems? That should help narrow things down a bit.


#13

So great minds think alike as I was trying to do that as well, but was getting an error:

root@testplex:~/go/src/github.com/ncw/rclone # go install -tags cmount
# github.com/ncw/rclone/vendor/github.com/billziss-gh/cgofuse/fuse
vendor/github.com/billziss-gh/cgofuse/fuse/fsop.go:28:2: error: platform not supported
#error platform not supported
 ^
1 error generated.

I can compile without the tags. I am seeing if I can fix that next.


#14

If I check the github, the files seem to be different.

go: downloading github.com/kr/fs v0.1.0
# github.com/billziss-gh/cgofuse/fuse
../go/pkg/mod/github.com/billziss-gh/cgofuse@v1.1.0/fuse/fsop.go:28:2: error: platform not supported
#error platform not supported

It looks like it’s pulling the latest release, but for FreeBSD, it needs to be the latest commit.


#15

I swapped out the files with the latest commit and got it mounted.

Got the same error unfortunately.

2019/02/12 11:24:17 DEBUG : Encrypted drive 'gcrypt:': Mounting with options: ["-o" "fsname=gcrypt:" "-o" "subtype=rclone" "-o" "max_readahead=131072" "-o" "attr_timeout=1" "-o" "atomic_o_trunc" "-o" "sync_read"
2019/02/12 11:24:43 DEBUG : Radarr_Movies/Unsane (2018)/Unsane (2018).mkv: Open: flags=O_WRONLY

#16

Well done for getting cmount to run.

I discovered where the O_WRONLY and the truncate come from

2019/02/08 12:30:12 DEBUG : Radarr_Movies/Unsane (2018)/Unsane (2018).mkv: Setattr: a=Setattr [ID=0x3b Node=0x4 Uid=0 Gid=0 Pid=1535] size=25938409160 handle=INVALID-0x0
2019/02/08 12:30:12 DEBUG : Radarr_Movies/Unsane (2018)/Unsane (2018).mkv: Truncating file
2019/02/08 12:30:12 DEBUG : Radarr_Movies/Unsane (2018)/Unsane (2018).mkv: Open: flags=O_WRONLY
2019/02/08 12:30:12 DEBUG : Radarr_Movies/Unsane (2018)/Unsane (2018).mkv: >Open: fd=Radarr_Movies/Unsane (2018)/Unsane (2018).mkv (w), err=<nil>
2019/02/08 12:30:12 ERROR : Radarr_Movies/Unsane (2018)/Unsane (2018).mkv: WriteFileHandle: Truncate: Can't change size without --vfs-cache-mode >= writes
2019/02/08 12:30:12 DEBUG : Radarr_Movies/Unsane (2018)/Unsane (2018).mkv: >Setattr: err=ope

It is from the Setattr call which is called to set the length of a file. I don’t know why FreeBSD is calling it though. I’m assuming that 25,938,409,160 is the correct size of the file.

I put a workaround which ignores truncate if it isn’t writing to a file and it already has the correct size. Hopefully this will fix the issue.

The underlying problem is probably a FreeBSD FUSE bug I’d guess since we got the same thing on mount and cmount.

https://beta.rclone.org/branch/v1.46.0-018-gb5f563fb-fix-mount-freebsd-beta/ (uploaded in 15-30 mins)


#17

Yep, that’s the right size.

-rw-rw-r-- 1 felix felix 25938409160 Jun 21  2018 Unsane (2018).mkv

I’ll open up a bug on the FreeBSD side and see.


#18

If you post the link I’ll keep an eye on it!


#19

Here is the Fuse issue I opened up.


#20

I has a look on the freeBSD bug tracker for kernel fuse bugs

I think this may be the same problem: https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=196726

Can you try the python program there and see if it gives the error on your system?