Bug 198967 - Modification times not preserved correctly
Summary: Modification times not preserved correctly
Status: RESOLVED CODE_FIX
Alias: None
Product: File System
Classification: Unclassified
Component: CIFS (show other bugs)
Hardware: All Linux
: P1 normal
Assignee: fs_cifs
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2018-03-02 08:13 UTC by Nadav Har'El
Modified: 2019-07-24 01:48 UTC (History)
3 users (show)

See Also:
Kernel Version: 4.15.3
Subsystem:
Regression: No
Bisected commit-id:


Attachments
strace and pcap data (57.79 KB, application/gzip)
2019-06-12 15:23 UTC, Jacob Shivers
Details
notes (4.75 KB, application/gzip)
2019-06-12 15:23 UTC, Jacob Shivers
Details
win2k16 strace and pcap data (22.17 KB, application/gzip)
2019-06-12 16:06 UTC, Jacob Shivers
Details
win2k19 strace and pcap data (19.07 KB, application/gzip)
2019-06-25 04:26 UTC, Jacob Shivers
Details

Description Nadav Har'El 2018-03-02 08:13:33 UTC
The problem I'm seeing is that "mv" or "cp -a" into a CIFS-mounted filesystem does NOT preserve the original file's modification time. The new file has the current date - not the original's file date.

The setting of a file's date to arbitrary time (e.g, with touch -r ...) does work correctly. This is why I think that what is happening is that "mv" or "cp -a" are setting the file's date correctly, but then some sort of later asynchronous close operation resets it again to the current time (similar to bug 6127 that used to exist in NFS).

This appears to be a regression - I haven't seen this problem before and I think I would have noticed.
Comment 1 Nadav Har'El 2018-03-02 08:19:52 UTC
By the way, by doing "ls -l" in parallel with the files being copied with "cp -a" I noticed that they *are* being set correctly to the original file's date, and only later, the date gets reset to the current date.

E.g.,

$ ls -l
-rwxr-xr-x. 1 nyh nyh 70234262 Apr  8  2017 VID_20170408_150943.mp4

$ ls -l
-rwxr-xr-x. 1 nyh nyh 70234262 Mar  2 10:15 VID_20170408_150943.mp4

Note how the file got the correct date (that also matches the date encoded in the file's name), but then later, it somehow got reset to today's date.
Comment 2 Steve French 2018-03-04 01:24:19 UTC
What is the server type and what is the dialect that is negotiated (is this cifs or smb3 or ...)
Comment 3 Nadav Har'El 2018-03-06 08:57:31 UTC
The server is a WD "My Cloud" (a home NAS), which until recently appears to have worked correctly (it's about two years old).
I don't know what dialect was negotiated - I am just mounting it without a "vers" option. Is there some command I can run to display the dialect or make some of query that can help you pinpoint the problem?

As I said, the mount is still working mostly correctly, except this file time issue. I thought this is a regression because I think (?) I would have noticed this problem earlier in my two years of using this NAS, although I can't really be sure (since I usually use rsync, not cp -a, and a second rsync would correct the wrong timestamp, I think).
Comment 4 Nadav Har'El 2018-03-06 09:57:41 UTC
I found the following /proc/fs/cifs/DebugData, maybe this answers your question about dialect? (I'm not sure if it does...)

Display Internal CIFS Data Structures for Debugging
---------------------------------------------------
CIFS Version 2.10
Features: dfs fscache lanman posix spnego xattr acl
Active VFS Requests: 0
Servers:
Number of credits: 41
1) Name: 192.168.0.183 Uses: 1 Capability: 0x300047     Session Status: 1      TCP status: 1
        Local Users To Server: 1 SecMode: 0x1 Req On Wire: 0
        Shares:
        1) \\192.168.0.183\Media Mounts: 1 DevInfo: 0x20 Attributes: 0x1006f
        PathComponentMax: 255 Status: 1 type: DISK 
        Share Capabilities: None Aligned, Partition Aligned,    Share Flags: 0x30       Optimal sector size: 0x200

        MIDs:
Comment 5 Nadav Har'El 2018-12-23 21:28:27 UTC
This bug still exists today (Linux 4.19.6-300.fc29.x86_64):

As I already suspected above, "mv"-ing a tiny file into that NAS (using CIFS) preserves its date, but for a large file it temporarily gets the right size and date but then (apparently) as the end of the file gets flushed, the date resets to the current date. I can reproduce the same problem with "cp -a", but "rsync -avP" seems to copy the date properly. I don't know how or why.

By the way, although this problem sounds benign, it's actually quite disruptive, because the last modification times of the moved files are destroyed after the original files have already been deleted. It more than once caused me to lose the dates on hundreds of files which I moved from disk to disk, without having any way to fix what happened.
Comment 6 Steve French 2018-12-23 21:36:07 UTC
You can tell the dialect from /proc/fs/cifs/DebugData.  This looks like an older cifs.ko although it often can be inferred from the "vers=" displayed in "/proc/mounts | grep cifs"

# cat /proc/fs/cifs/DebugData 
Display Internal CIFS Data Structures for Debugging
---------------------------------------------------
CIFS Version 2.14
Features: DFS,FSCACHE,STATS,DEBUG,ALLOW_INSECURE_LEGACY,WEAK_PW_HASH,CIFS_POSIX,UPCALL(SPNEGO),XATTR,ACL
Active VFS Requests: 0
Servers:
Number of credits: 57 Dialect 0x302
...

The key question here is whether the client sent the wrong time (or set the time before the last write) or whether the server did this wrong.  It will be fairly easy to spot by looking at the last five or ten frames of it in a network trace. 

https://wiki.samba.org/index.php/LinuxCIFS_troubleshooting#Wire_Captures
Comment 7 Jacob Shivers 2019-01-25 15:45:25 UTC
There was a recent discussion of this issue on linux-cifs and samba-technical lists.

I ran into this issue with `# cp -p`, but after reproducing the issue and getting some additional eyes, this looks to be a client side issue.

  ** Fwd: SMB2 not respecting mtime values **
  https://lists.samba.org/archive/samba-technical/2019-January/132132.html

The Linux SMB client is using two different file handles.
One file handle for writing and another for setting the modification time.

Either the client should use the same handle for setting the mtime as for the write OR there needs to be an open for the second handle.

$ tshark -n -r cp_p-testing-5.0.0-0.rc2.git2.1.fc30.x86_64-trimmed.pcap -Y '(smb2.cmd == write && smb2.flags.response == 0) || (smb2.cmd == setinfo && smb2.filename == test_file-data)'
   47  80.932199 192.168.124.142 → 192.168.124.133 SMB2 194 Write Request Len:12 Off:0 File: test_file-data
   49  80.933615 192.168.124.142 → 192.168.124.133 SMB2 446 Create Request File: test_file-data;SetInfo Request FILE_INFO/SMB2_FILE_BASIC_INFO;Close Request

$ tshark -n -r cp_p-testing-5.0.0-0.rc2.git2.1.fc30.x86_64-trimmed.pcap -Y '(smb2.cmd == write && smb2.flags.response == 0) || (smb2.cmd == setinfo && smb2.filename == test_file-data)' -T fields -e smb2.fid
00000f0c-0005-0000-1d00-000005000000
ffffffff-ffff-ffff-ffff-ffffffffffff,ffffffff-ffff-ffff-ffff-ffffffffffff
Comment 8 Nadav Har'El 2019-03-15 08:45:57 UTC
Thanks, I agree that this has to be a "client side" (the Linux SMB client side) because it appears to be a regression - a new problem that started happening about a year ago, with an existing and unchanged server.

I'm still seeing this problem often, I'm surprised we don't get here dozens of "Me Too!" - how are people moving files from a Linux machine into a CIFS network drives?
Comment 9 Jacob Shivers 2019-06-12 15:21:06 UTC
I finally got around to making time to work on this.
Regarding the 'client side' versus 'server side' behavior, there are two actual separate issues.

Going back to the 3.16.66 kernel, we can readily reproduce this behavior where mtime is not respected. However, this is not a client side issue.

The client is correctly setting atime and mtime to proper file handles and only atime is being respected. In newer kernels, what appears to be different on the client end is due to 9b9c5bea0b960616d638711d0ecc270c3a074e7f.

$ git show 9b9c5bea0b960616d638711d0ecc270c3a074e7f | head -20 
commit 9b9c5bea0b960616d638711d0ecc270c3a074e7f
Author: Steve French <stfrench@microsoft.com>
Date:   Sat Sep 22 12:07:06 2018 -0500

    cifs: do not return atime less than mtime
    
    In network file system it is fairly easy for server and client
    atime vs. mtime to get confused (and atime updated less frequently)
    which we noticed broke some apps which expect atime >= mtime
    
    Also ignore relatime mount option (rather than error on it) since
    relatime is basically what some network server fs are doing
    (relatime).
    
    Signed-off-by: Steve French <stfrench@microsoft.com>
    Reviewed-by: Ronnie Sahlberg <lsahlber@redhat.com>


Due to the SMB server not properly logging mtime, the atime returned by cifs.ko just matches mtime. It should be noted that the server returns the correct atime.

I am attaching strace+pcap data as well as more detailed notes for those that want to review.

Post the above commit, it could be viewed as a regression, but this is debatable.

I've tested against the latest Samba release as well as a Windows 2k16 server and both exhibit the same behavior.
Comment 10 Jacob Shivers 2019-06-12 15:23:06 UTC
Created attachment 283223 [details]
strace and pcap data

contains strace and pcap data from `# cp -p` operations with empty and non-empty files across three different kernels. An older 3.16 release, the latest stable 4.19 that is pre-compound, and a fairly recent upstream.
Comment 11 Jacob Shivers 2019-06-12 15:23:56 UTC
Created attachment 283225 [details]
notes

additional notes and reproducer steps
Comment 12 Jacob Shivers 2019-06-12 16:04:14 UTC
I am attaching additional data from copying to a win2k16 SMB server.
Comment 13 Jacob Shivers 2019-06-12 16:06:24 UTC
Created attachment 283229 [details]
win2k16 strace and pcap data

win2k16 data set.
Comment 14 Jacob Shivers 2019-06-25 04:26:59 UTC
Created attachment 283421 [details]
win2k19 strace and pcap data
Comment 15 Jacob Shivers 2019-06-25 04:35:06 UTC
I've attached strace and pcap data from copying to a Win2k19 SMB server.
atime/mtime are correctly stored on the SMB server.

Steve French tested against a Win10 SMB server and also confirmed that atime/mtime is correctly copied to the SMB server.
Comment 16 Ronnie Sahlberg 2019-07-24 01:48:15 UTC
I think this has been fixed now for preserving mtime when using "cp -p" :

commit aa081859b10c5d8b19f5c525c78883a59d73c2b8
Author: Ronnie Sahlberg <lsahlber@redhat.com>
Date:   Fri Jul 19 08:12:11 2019 +1000

    cifs: flush before set-info if we have writeable handles
    
    Servers can defer destaging any data and updating the mtime until close().
    This means that if we do a setinfo to modify the mtime while other handles
    are open for write the server may overwrite our setinfo timestamps when
    if flushes the file on close() of the writeable handle.
    
    To solve this we add an explicit flush when the mtime is about to
    be updated.
    
    This fixes "cp -p" to preserve mtime when copying a file onto an SMB2 share.
    
    CC: Stable <stable@vger.kernel.org>
    Signed-off-by: Ronnie Sahlberg <lsahlber@redhat.com>
    Reviewed-by: Pavel Shilovsky <pshilov@microsoft.com>
    Signed-off-by: Steve French <stfrench@microsoft.com>

Note You need to log in before you can comment on or make changes to this bug.