[Bug 245689] Chmod performs unnecessary access calls (FUSE fs)

Fri Apr 17 10:28:05 UTC 2020

https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=245689

            Bug ID: 245689
           Summary: Chmod performs unnecessary access calls (FUSE fs)
           Product: Base System
           Version: 12.1-RELEASE
          Hardware: amd64
                OS: Any
            Status: New
          Severity: Affects Some People
          Priority: ---
         Component: kern
          Assignee: bugs at FreeBSD.org
          Reporter: freebsd at moosefs.pro

FreeBSD 12.1-p2, MooseFS mounted via FUSE ver 3.

We perform the following operations:

$ touch test.txt ; chmod u-w test.txt ; chmod u+w test.txt
chmod: test.txt: Permission denied

What happens on the fs side:

# touch test.txt
04.08 09:58:05.000715: uid:1001 gid:0 pid:48262 cmd:access (504599,0x1): OK
04.08 09:58:05.001324: uid:1001 gid:0 pid:48262 cmd:lookup (504599,test.txt):
ENOENT (No such file or directory)
04.08 09:58:05.001731: uid:1001 gid:0 pid:48262 cmd:access (504599,0x1): OK
04.08 09:58:05.002157: uid:1001 gid:0 pid:48262 cmd:lookup (504599,test.txt):
ENOENT (No such file or directory)
04.08 09:58:05.002546: uid:1001 gid:0 pid:48262 cmd:access (504599,0x2): OK
04.08 09:58:05.002946: uid:1001 gid:0 pid:48262 cmd:create
(504599,test.txt,-rw-r--r--:0100644): OK
(0.0,1238695,1.0,[-rw-r--r--:0100644,1,1001,0,1586332685,1586332685,1586332685,0])
(direct_io:0,keep_cache:0) [handle:03000001]
04.08 09:58:05.003013: uid:1001 gid:0 pid:48262 cmd:flush (1238695)
[handle:03000001,uselocks:0,lock_owner:000000000000BC86]: OK
04.08 09:58:05.003249: uid:1001 gid:0 pid:48262 cmd:release (1238695)
[handle:03000001,uselocks:0,lock_owner:000000000000BC86]: OK
# chmod u-w test.txt
04.08 09:58:05.005207: uid:1001 gid:0 pid:48263 cmd:access (504599,0x1): OK
04.08 09:58:05.005668: uid:1001 gid:0 pid:48263 cmd:lookup (504599,test.txt):
OK
(0.0,1238695,1.0,[-rw-r--r--:0100644,1,1001,0,1586332685,1586332685,1586332685,0])
04.08 09:58:05.006095: uid:1001 gid:0 pid:48263 cmd:access (504599,0x1): OK
04.08 09:58:05.006490: uid:1001 gid:0 pid:48263 cmd:lookup (504599,test.txt):
OK
(0.0,1238695,1.0,[-rw-r--r--:0100644,1,1001,0,1586332685,1586332685,1586332685,0])
04.08 09:58:05.006888: uid:1001 gid:0 pid:48263 cmd:access (504599,0x1): OK
04.08 09:58:05.007260: uid:1001 gid:0 pid:48263 cmd:lookup (504599,test.txt):
OK
(0.0,1238695,1.0,[-rw-r--r--:0100644,1,1001,0,1586332685,1586332685,1586332685,0])
04.08 09:58:05.007292: uid:1001 gid:0 pid:48263 cmd:access (1238695,0x2): OK
04.08 09:58:05.007903: uid:1001 gid:0 pid:48263 cmd:setattr
(1238695,0x1,[mode=r--r--r--:00444]) [no handle]: OK
(1.0,[-r--r--r--:0100444,1,1001,0,1586332685,1586332685,1586332685,0])
# chmod u+w test.txt
04.08 09:58:05.009607: uid:1001 gid:0 pid:48264 cmd:access (504599,0x1): OK
04.08 09:58:05.009944: uid:1001 gid:0 pid:48264 cmd:lookup (504599,test.txt):
OK
(0.0,1238695,1.0,[-r--r--r--:0100444,1,1001,0,1586332685,1586332685,1586332685,0])
04.08 09:58:05.010879: uid:1001 gid:0 pid:48264 cmd:access (504599,0x1): OK
04.08 09:58:05.011309: uid:1001 gid:0 pid:48264 cmd:lookup (504599,test.txt):
OK
(0.0,1238695,1.0,[-r--r--r--:0100444,1,1001,0,1586332685,1586332685,1586332685,0])
04.08 09:58:05.011680: uid:1001 gid:0 pid:48264 cmd:access (504599,0x1): OK
04.08 09:58:05.012068: uid:1001 gid:0 pid:48264 cmd:lookup (504599,test.txt):
OK
(0.0,1238695,1.0,[-r--r--r--:0100444,1,1001,0,1586332685,1586332685,1586332685,0])
04.08 09:58:05.012102: uid:1001 gid:0 pid:48264 cmd:access (1238695,0x2):
EACCES (Permission denied)
04.08 09:58:05.596937: uid:0 gid:0 pid:48228 cmd:getattr (504599) [no handle]:
OK (1.0,[drwxr-xr-x:0040755,3,1001,0,1586332657,1586332685,1586332685,1002246])

So, we have an "access" call to a file that has no "w" permission for the user
calling, so we get an EACCES...

There are 2 problems here:
1) It is not necessary to have "w" permission to a file to change its metadata
- this only requires the uid doing the changes to be either 0 or owner of the
file.
2) MooseFS does NOT send "default_permissions" when initializing FUSE, so the
whole checking of permissions should happen on the filesystem side. Yet,
practically all the calls are preceded with access calls.

Here is how the above chmod operations look on Linux:

# chmod u-w test.txt
04.08 10:10:26.794571: uid:1000 gid:1000 pid:30550 cmd:lookup
(164872,test.txt): OK
(0.0,210456,1.0,[-rw-r--r--:0100644,1,1000,1000,1586326757,1586326757,1586326769,0])
04.08 10:10:26.794717: uid:1000 gid:1000 pid:30550 cmd:lookup
(164872,test.txt): OK
(0.0,210456,1.0,[-rw-r--r--:0100644,1,1000,1000,1586326757,1586326757,1586326769,0])
04.08 10:10:26.802672: uid:1000 gid:1000 pid:30550 cmd:setattr
(210456,0x1,[mode=r--r--r--:00444]) [no handle]: OK
(1.0,[-r--r--r--:0100444,1,1000,1000,1586326757,1586326757,1586333426,0])
# chmod u+w test.txt
04.08 10:10:26.803478: uid:1000 gid:1000 pid:30551 cmd:lookup
(164872,test.txt): OK
(0.0,210456,1.0,[-r--r--r--:0100444,1,1000,1000,1586326757,1586326757,1586333426,0])
04.08 10:10:26.803608: uid:1000 gid:1000 pid:30551 cmd:lookup
(164872,test.txt): OK
(0.0,210456,1.0,[-r--r--r--:0100444,1,1000,1000,1586326757,1586326757,1586333426,0])
04.08 10:10:26.803790: uid:1000 gid:1000 pid:30551 cmd:setattr
(210456,0x1,[mode=rw-r--r--:00644]) [no handle]: OK
(1.0,[-rw-r--r--:0100644,1,1000,1000,1586326757,1586326757,1586333426,0])

There are no "access" calls at all.

While problem 1) is a simple bug, problem 2) is a serious performance issue.
MooseFS is a network filesystem and performance is very important in this case
- it has to receive and handle twice as many calls sent via network.

-- 
You are receiving this mail because:
You are the assignee for the bug.