Bug 14473 - s3:modules fix excessive logging if vfs_fruit when fruit:metadata = stream
Summary: s3:modules fix excessive logging if vfs_fruit when fruit:metadata = stream
Status: NEW
Alias: None
Product: Samba 4.1 and newer
Classification: Unclassified
Component: VFS Modules (show other bugs)
Version: 4.10.17
Hardware: All All
: P5 normal (vote)
Target Milestone: ---
Assignee: Ralph Böhme
QA Contact: Samba QA Contact
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2020-08-27 13:56 UTC by Andrew Walker
Modified: 2020-08-27 18:00 UTC (History)
0 users

See Also:


Attachments
Interesting stuff begins at 176 (1.70 MB, application/vnd.tcpdump.pcap)
2020-08-27 13:56 UTC, Andrew Walker
no flags Details
test file with icon (74.10 KB, application/zip)
2020-08-27 13:59 UTC, Andrew Walker
no flags Details
pcap from macos server (1020.76 KB, application/zip)
2020-08-27 14:31 UTC, Andrew Walker
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Andrew Walker 2020-08-27 13:56:33 UTC
Created attachment 16186 [details]
Interesting stuff begins at 176

MacOS clients may in some situations compound an SMB2 CREATE and READ for AFP
Info stream before one exists on the file. In the initial open() when fruit is configured to store metadata as stream, O_CREAT flag is removed before passing to streams_xattr. This results in streams_xattr not generating an FSP extension and the subsequent pread() to fall through streams_xattr and get picked up eventually by the default pread(), which in this case returns 0. vfs_fruit flags this as a short read, generates log message at DBG_ERR, then tries to remove the non-existent xattr generating a second log message at DBG_ERR.


WIP fix here:
https://gitlab.com/samba-team/devel/samba/-/commits/anodos325-fix-excessive-logging-in-fruit
Comment 1 Andrew Walker 2020-08-27 13:57:07 UTC
Comment on attachment 16186 [details]
Interesting stuff begins at 176

This is a pcap of MacOS client writing to samba 4.10.17.
Comment 2 Andrew Walker 2020-08-27 13:59:48 UTC
Created attachment 16187 [details]
test file with icon

This is the file I was using for testing issue. Procedure is to copy / paste into SMB share.
Comment 3 Andrew Walker 2020-08-27 14:01:17 UTC
Sample log message:
[2020/08/27 14:26:56.776316,  0] ../../source3/modules/vfs_fruit.c:4240(fruit_pread_meta_stream)
  fruit_pread_meta_stream: Removing [Finder Refresh.app:AFP_AfpInfo] after short read [0]
[2020/08/27 14:26:56.776462,  0] ../../source3/modules/vfs_fruit.c:4244(fruit_pread_meta_stream)
  fruit_pread_meta_stream: Removing [Finder Refresh.app:AFP_AfpInfo] failed
Comment 4 Andrew Walker 2020-08-27 14:31:14 UTC
Created attachment 16188 [details]
pcap from macos server

Compounded CREATE | READ on AFPInfo is in 2118 and 2223
Comment 5 Andrew Walker 2020-08-27 15:05:05 UTC
Sorry 2113 and 2118.

It appears like in this case MacOS server is returning basic AFPInfo xattr.