[cifs-protocol] Excel timestamp client side-caching request

Jeremy Allison jra at samba.org
Wed Aug 5 15:46:44 MDT 2009


Hi Hongwei,

As requested here is a write up of the Excel
timestamps issue I've discovered with client
side caching turned on.

To reproduce. Use Windows Vista with Microsoft
Office 2003 :

Set up a share called "offline", containing a
single Excel file "test.xls".

Mount this share as drive z:, then open with

explorer z:

Right click on the test.xls file and enable
"Make this file available offline".

Then double click text.xls to open the file,
and *immediately* (as soon as the Excel window
opens) click on the "X" (top right hand corner)
to close Excel.

Then right click on test.xls and select "Sync".
Against a Windows 2003 server this always works,
against a Samba server it intermittently (50%
to 90% of the time) fails. The symptom is that
the "Sync" icon in the lower bar shows a "!"
icon, and looking at the synchronization failure
shows that the last write timestamp on the file
on the remote server has been updated to the
current time at open, instead of being the same
as the original last write time which is being
stored in the cache on the local Vista client.

What is going on under the covers
---------------------------------

On selecting "Make this file available offline"
the file (and metadata is copied locally onto
the Vista client).

When the file is double clicked and opened
by Excel, the sequence of events is that the
file is opened with NTCreateX, then the last
write time is set to the current time using
SET_FILE_INFO, then part of the file is written
to (I'm assuming to enable synchronization info
to be conveyed to another process trying to
open this .xls file at the same time).

When the .xls file is closed, the client
*should* then use SET_FILE_INFO to restore
the last write time to the original last write
time that was originally read before the file
was opened.

Against a Samba server the client does this
*sometimes*, but not reliably and I'm trying
to figure out why.

I'm enclosing two packet capture traces.

The first is called "office2003-openclose-samba-bad.pcap"
and is the above scenario being done from a
Vista client (IP address: 172.18.102.177) to a
Samba server (IP address: 172.18.102.85).

The meta data of the .XLS file on the Samba server
is :

  File: `test.xls'
  Size: 811520    	Blocks: 1608       IO Block: 4096   regular file
Device: 806h/2054d	Inode: 11567162    Links: 1
Access: (0666/-rw-rw-rw-)  Uid: (41427/     jra)   Gid: ( 5000/     eng)
Access: 2009-07-22 12:00:00.000000000 -0700
Modify: 2009-07-31 00:00:00.000000000 -0700
Change: 2009-08-04 10:21:49.000000000 -0700

This is a modified version of Samba that stores
the create time in the "access" field of the POSIX
timestamp, on a filesystem mounted with "noatime"
so that field is free to use by Samba as the create
time.

Packets 0 - 900 show the right click -> Set Offline
action from explorer.

Packets 958 - 2079 show the open/close being done
by Excel on the file - note this is an example of
a "correct" operation by the client (in that it resets
the "last write" timestamp correctly back to the
server).

Packets 2080 - 2200 show the right click -> Sync
action from explorer (that succeeds).

The rest of the packets 2201 - 2976 show
the open/close right click -> Sync operation
being done again immediately against the .XLS
file, and this time the operation fails (the
last write timestamp is not correctly reset).

The interesting packets are :

1043: SET_FILE_INFO setting the last write time to the
current time.

1882: SET_FILE_INFO resetting the last write time
to the original time (2009-07-31 00:00:00.000000000 -0700)
- this is the step that is missing from the second
operation that causes the sync to succeed.

2262: SET_FILE_INFO setting the last write time to the
current time.

Note that in this second case there is no follow up
SET_FILE_INFO to reset the time to the correct original
value.

What I'm trying to find out is what it is within
the data Samba is returning to the client that causes
the client to fail to restore the original timestamp
in the case where CSC sync caching is turned on.

As a comparison, I'm including a packet trace from
the same client against a Win2K3 server, called :
office2003-open-close-windows-good.cap.

This is exactly the same sequence of operations
against a Win2k3 server, with IP address : 172.18.103.237
(the client IP address is still 172.18.102.177).
The file in this case is called Book1.xls.

The interesting packets in this trace are:

1216: SET_FILE_INFO setting the last write time to the
current time.

1513: SET_FILE_INFO resetting the last write time
to the original time.

This sequence of events is always seen in the traces
to a Windows server, but only intermittently seen in
the traces to a Samba server.

My first thoughts were this was a change notify
issue, so the version of Samba being used for this
trace emulates perfectly (as far as I can tell) the
change notify replies as seen from a Windows server,
yet the problem remains.

Any help tracking down what is different about
the timestamp or other meta data replies that
cause the Vista + Office 2003 + CSC client to
behave differently against a Samba server will
be gratefully received.

Thanks,

Jeremy.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: office2003-openclose-samba-bad.pcap
Type: application/cap
Size: 124789 bytes
Desc: not available
URL: <http://lists.samba.org/pipermail/cifs-protocol/attachments/20090805/687e4f49/attachment-0001.pcap>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: office2003-open-close-windows-good.cap
Type: application/cap
Size: 1151561 bytes
Desc: not available
URL: <http://lists.samba.org/pipermail/cifs-protocol/attachments/20090805/687e4f49/attachment-0001.cap>


More information about the cifs-protocol mailing list