Excel timestamp client side-caching request
|
View:
New views
10 Messages
—
Rating Filter:
Alert me
|
 |
Excel timestamp client side-caching request
by Jeremy Allison
::
Rate this Message:
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. _______________________________________________ cifs-protocol mailing list cifs-protocol@... https://lists.samba.org/mailman/listinfo/cifs-protocol  office2003-openclose-samba-bad.pcap (167K) Download Attachment office2003-open-close-windows-good.cap (1M) Download Attachment |
|
|
Re: Excel timestamp client side-caching request
by Hongwei Sun
::
Rate this Message:
|
|
|
Re: Excel timestamp client side-caching request
by Hongwei Sun
::
Rate this Message:
|
|
|
Re: Excel timestamp client side-caching request
by Jeremy Allison
::
Rate this Message:
|
|
|
Re: Excel timestamp client side-caching request
by Hongwei Sun
::
Rate this Message:
|
|
|
Re: Excel timestamp client side-caching request
by Jeremy Allison
::
Rate this Message:
|
|
|
Re: Excel timestamp client side-caching request
by Hongwei Sun
::
Rate this Message:
Some parts of this message have been removed.
Learn more about Nabble's security policy.
Jeremy, After much of testing and debugging,
it seems that we are getting the cause why Windows takes the file offline and
the timestamp update only goes to local store. When Windows close
one particular handle through which the file had been modified, it queries the
timestamps using FIND_FIRST2 on the file after receiving the close response.
Those timestamps are then saved in CSC cache. We can see that the LastWriteTime
value returned from the create response does not match the value returned from
FIND_FRIST2 query. The mismatch of LastWriteTime causes Windows to declare
the version conflict between server copy and local cache and thus takes it
offline. Here are the details shown in the traces you
sent us.. Office2003-opnclose-samba-bad.cap: Opening file, the current
time stamp is written to the excel file Frame
175 10.20.0.111 10.20.0.66 SMB Trans2 Response,
FIND_FIRST2, Files: excel test.xls Last Write: Jul 8, 2009
15:10:06.000000000 Frame
185 10.20.0.111 10.20.0.66 SMB NT Create AndX
Response, FID: 0x13ff Last
Write: Jul 8, 2009 15:10:06.000000000 Frame
214 10.20.0.66 10.20.0.111 SMB Trans2 Request,
SET_FILE_INFO, FID: 0x13ff So far so good.. Closing file, the original
time stamp is supposed to be restored to the excel file
Frame 574 10.20.0.111 10.20.0.66 SMB Trans2
Response, FIND_FIRST2, Files: excel test.xls Last Write: Jul 8,
2009 19:36:12.294000000 Frame
587 10.20.0.111 10.20.0.66 SMB NT Create AndX
Response, FID: 0x103e
Last Write: Jul 8, 2009 19:36:12.000000000 Mismatch of time stamp is
detected and remote file is closed and it is going offline. SET_FILEINFO
will not sent to the server any update will only goes to local
copy.
Frame 588 10.20.0.66 10.20.0.111 SMB Close
Request, FID: 0x103e From all the failed cases I got, I can
see that only the millisecond part is different. You may look at the difference between
logics of those two commands regarding LastWriteTime. Please let me know what
you think and, if necessary, we can continue working together to debug the
problem. Thanks! Hongwei -----Original Message----- On Sun, Aug 16, 2009 at 05:34:39AM +0000, Hongwei Sun
wrote: > Jeremy, > > We are still working on
identifying the issue. It seems that when Excel tries to send SET_INFO
when closing the file, CSC thinks ,for some reason, that the object is in
disconnected offline state and any update to the file is just applied to the
CSC local cache. That is why the SMB Transact2 request is not really sent
over the wire. It looks like that it is timing related as I have much
smaller chance to capture the condition if it is running under debugger. > > I will be on vacation next week until
Friday. Nick and Edgar will continue working on the issue. If
you have any information or requests, please let us know. We will also
let you know as soon as we get the root cause on the issue. Ok, this is very interesting. If there's anything I can
do to help please let me know but it does sound like there's something the Windows CSC code sees from a Samba server that it doesn't like and causes it to make the decision that the drive is offline. You guys are in the best place to determine what that might be. Thanks, Jeremy. _______________________________________________ cifs-protocol mailing list cifs-protocol@... https://lists.samba.org/mailman/listinfo/cifs-protocol |
|
|
Re: Excel timestamp client side-caching request
by Jeremy Allison
::
Rate this Message:
|
|
|
Re: Excel timestamp client side-caching request
by Hongwei Sun
::
Rate this Message:
|
|
|
Re: Excel timestamp client side-caching request
by Jeremy Allison
::
Rate this Message:
|
| Free embeddable forum powered by Nabble | Forum Help |
