[OpenAFS] OpenAfs and MS Office: Delayed Write Failed

Jeffrey Altman jaltman@secure-endpoints.com
Tue, 23 May 2006 18:06:13 -0400


This is a cryptographically signed message in MIME format.

--------------ms020209060004010408070108
Content-Type: text/plain; charset=ISO-8859-1
Content-Transfer-Encoding: 7bit

I have been able to reproduce the problem on my system.  The scenario
is that the Windows CIFS client is breaking the connection while there
are dozens of CIFS Write requests outstanding.  The client appears to
break the connection on my system when the oldest outstanding connection
has been waiting for 90 seconds.

You can increase the wait period by setting this registry value to
a higher value.  Perhaps 120 or 180 seconds.

[HKLM\SYSTEM\CurrentControlSet\Services\lanmanworkstation\parameters]
SessTimeout

This problem is exacerbated by the fact that requests in process within
the cache manager are not prioritized by age and they can be processed
out of order.  When there are many outstanding requests some requests
end up waiting longer than is desirable.

This problem will only go completely away when the CIFS interface
is replaced by an IFS.  Only then will there not be an arbitrary
timeout applied to operations.

Jeffrey Altman


Jeffrey Altman wrote:
> Frank:
> 
> You are consistently receiving an "IN PAGE ERROR" unfortunately
> there do not appear to be any errors occurring on the AFS CIFS
> server side of the connection.  The CIFS client is simply breaking the
> connection at some point.
> 
> A couple of questions:
> 
> * what version of Word are you using?  When I monitor Word 2003 SP2
>   I see that most of the writing is being performed by SYSTEM and not
>   by WINWORD.EXE.  This is because Word is using asynchronous background
>   writes. In your log data I see all of the data being written by
>   WINWORD.EXE.
> 
> * what version of OpenAFS for Windows is this log generated with?
> 
> The debug monitor log shows that shortly after the file monitor
> logs the IN PAGE ERROR, the AFS cache manager receives a number of
> TellMeAboutYourself requests from AFS File Servers.  This often
> indicates that there was a network failure of some kind as the
> servers are responding to the establishment of a new rx connection.
> If the network dropped on the machine, the Windows CIFS client would
> respond by closing all of the existing connections.  Perhaps that
> is what you are seeing.  Its not clear from the logs that anything
> unusual is taking place.
> 
> Jeffrey Altman
> 
> 
> Frank Burkhardt wrote:
>> Hi,
>>
>> On Mon, May 22, 2006 at 09:31:04AM -0400, Jeffrey Altman wrote:
>>> Please generate the logs again and this time make sure that "Clock Time"
>>> and "Show Milliseconds" are selected in both DbgView and FileMon prior
>>> to capturing the log data.  This will allow the events in one log to be
>>> synchronized with the data in the other log.
>> Here they are:
>>
>>  http://fbo.no-ip.org/mail-temp/crash-debug-23052006.log
>>  http://fbo.no-ip.org/mail-temp/crash-filemon-23052006.log
>>   
>> Regards,
>>
>> Frank
>> _______________________________________________
>> OpenAFS-info mailing list
>> OpenAFS-info@openafs.org
>> https://lists.openafs.org/mailman/listinfo/openafs-info
> 

--------------ms020209060004010408070108
Content-Type: application/x-pkcs7-signature; name="smime.p7s"
Content-Transfer-Encoding: base64
Content-Disposition: attachment; filename="smime.p7s"
Content-Description: S/MIME Cryptographic Signature

MIAGCSqGSIb3DQEHAqCAMIACAQExCzAJBgUrDgMCGgUAMIAGCSqGSIb3DQEHAQAAoIIJXzCC
AwowggJzoAMCAQICAw7NrTANBgkqhkiG9w0BAQQFADBiMQswCQYDVQQGEwJaQTElMCMGA1UE
ChMcVGhhd3RlIENvbnN1bHRpbmcgKFB0eSkgTHRkLjEsMCoGA1UEAxMjVGhhd3RlIFBlcnNv
bmFsIEZyZWVtYWlsIElzc3VpbmcgQ0EwHhcNMDUwNTI3MTc0NzU3WhcNMDYwNTI3MTc0NzU3
WjBzMQ8wDQYDVQQEEwZBbHRtYW4xFTATBgNVBCoTDEplZmZyZXkgRXJpYzEcMBoGA1UEAxMT
SmVmZnJleSBFcmljIEFsdG1hbjErMCkGCSqGSIb3DQEJARYcamFsdG1hbkBzZWN1cmUtZW5k
cG9pbnRzLmNvbTCCASIwDQYJKoZIhvcNAQEBBQADggEPADCCAQoCggEBAKjPyrF+rdjOUSK/
bWwZHdx5p1+y6iiCd4vvYEVDxouYFp5C/fZEWm5n45ubBUbMSUI1MAZN6ooEoH09UTj6BXhM
S8B987ls81dKOIUphTF2jOzq8gsFmeA15yHMRAD20LqUWeLyvYk8FCNQw+dsKMMhX+WdsxOm
RY/1jPkJL6oN8kEwoUFkOX9/OfWWh6oFnV6faiEHUKDMFubsb9X0KVD8iIeR7Cxz7i4kXqRX
wMlp2fyoxcDIJrBaTY8nA++g3p34IkWt1a5po6g683nIgSnGpwYIwuJheBqSEZfLYWa+1KdD
6Sn27Ud94GqUvPVG5jC6zVC5EJ2aWuoAu+nNuV8CAwEAAaM5MDcwJwYDVR0RBCAwHoEcamFs
dG1hbkBzZWN1cmUtZW5kcG9pbnRzLmNvbTAMBgNVHRMBAf8EAjAAMA0GCSqGSIb3DQEBBAUA
A4GBADtvO//tjiAV6VJGtoNtrl34mB5jGyGTiotzw8riB6zz0GvY11bcWDmp6JKif+pVG+8L
IySDosbuva13qu2HwYUxBmWc7CoNd2k9kRlcrfbDUTTrGOZK8qyqNqT3gQZTAa9ZnUI0su9G
y/n2o5bQcaYdqR3htNrpvdLSPOWhILOXMIIDCjCCAnOgAwIBAgIDDs2tMA0GCSqGSIb3DQEB
BAUAMGIxCzAJBgNVBAYTAlpBMSUwIwYDVQQKExxUaGF3dGUgQ29uc3VsdGluZyAoUHR5KSBM
dGQuMSwwKgYDVQQDEyNUaGF3dGUgUGVyc29uYWwgRnJlZW1haWwgSXNzdWluZyBDQTAeFw0w
NTA1MjcxNzQ3NTdaFw0wNjA1MjcxNzQ3NTdaMHMxDzANBgNVBAQTBkFsdG1hbjEVMBMGA1UE
KhMMSmVmZnJleSBFcmljMRwwGgYDVQQDExNKZWZmcmV5IEVyaWMgQWx0bWFuMSswKQYJKoZI
hvcNAQkBFhxqYWx0bWFuQHNlY3VyZS1lbmRwb2ludHMuY29tMIIBIjANBgkqhkiG9w0BAQEF
AAOCAQ8AMIIBCgKCAQEAqM/KsX6t2M5RIr9tbBkd3HmnX7LqKIJ3i+9gRUPGi5gWnkL99kRa
bmfjm5sFRsxJQjUwBk3qigSgfT1ROPoFeExLwH3zuWzzV0o4hSmFMXaM7OryCwWZ4DXnIcxE
APbQupRZ4vK9iTwUI1DD52wowyFf5Z2zE6ZFj/WM+Qkvqg3yQTChQWQ5f3859ZaHqgWdXp9q
IQdQoMwW5uxv1fQpUPyIh5HsLHPuLiRepFfAyWnZ/KjFwMgmsFpNjycD76DenfgiRa3Vrmmj
qDrzeciBKcanBgjC4mF4GpIRl8thZr7Up0PpKfbtR33gapS89UbmMLrNULkQnZpa6gC76c25
XwIDAQABozkwNzAnBgNVHREEIDAegRxqYWx0bWFuQHNlY3VyZS1lbmRwb2ludHMuY29tMAwG
A1UdEwEB/wQCMAAwDQYJKoZIhvcNAQEEBQADgYEAO287/+2OIBXpUka2g22uXfiYHmMbIZOK
i3PDyuIHrPPQa9jXVtxYOanokqJ/6lUb7wsjJIOixu69rXeq7YfBhTEGZZzsKg13aT2RGVyt
9sNRNOsY5kryrKo2pPeBBlMBr1mdQjSy70bL+fajltBxph2pHeG02um90tI85aEgs5cwggM/
MIICqKADAgECAgENMA0GCSqGSIb3DQEBBQUAMIHRMQswCQYDVQQGEwJaQTEVMBMGA1UECBMM
V2VzdGVybiBDYXBlMRIwEAYDVQQHEwlDYXBlIFRvd24xGjAYBgNVBAoTEVRoYXd0ZSBDb25z
dWx0aW5nMSgwJgYDVQQLEx9DZXJ0aWZpY2F0aW9uIFNlcnZpY2VzIERpdmlzaW9uMSQwIgYD
VQQDExtUaGF3dGUgUGVyc29uYWwgRnJlZW1haWwgQ0ExKzApBgkqhkiG9w0BCQEWHHBlcnNv
bmFsLWZyZWVtYWlsQHRoYXd0ZS5jb20wHhcNMDMwNzE3MDAwMDAwWhcNMTMwNzE2MjM1OTU5
WjBiMQswCQYDVQQGEwJaQTElMCMGA1UEChMcVGhhd3RlIENvbnN1bHRpbmcgKFB0eSkgTHRk
LjEsMCoGA1UEAxMjVGhhd3RlIFBlcnNvbmFsIEZyZWVtYWlsIElzc3VpbmcgQ0EwgZ8wDQYJ
KoZIhvcNAQEBBQADgY0AMIGJAoGBAMSmPFVzVftOucqZWh5owHUEcJ3f6f+jHuy9zfVb8hp2
vX8MOmHyv1HOAdTlUAow1wJjWiyJFXCO3cnwK4Vaqj9xVsuvPAsH5/EfkTYkKhPPK9Xzgnc9
A74r/rsYPge/QIACZNenprufZdHFKlSFD0gEf6e20TxhBEAeZBlyYLf7AgMBAAGjgZQwgZEw
EgYDVR0TAQH/BAgwBgEB/wIBADBDBgNVHR8EPDA6MDigNqA0hjJodHRwOi8vY3JsLnRoYXd0
ZS5jb20vVGhhd3RlUGVyc29uYWxGcmVlbWFpbENBLmNybDALBgNVHQ8EBAMCAQYwKQYDVR0R
BCIwIKQeMBwxGjAYBgNVBAMTEVByaXZhdGVMYWJlbDItMTM4MA0GCSqGSIb3DQEBBQUAA4GB
AEiM0VCD6gsuzA2jZqxnD3+vrL7CF6FDlpSdf0whuPg2H6otnzYvwPQcUCCTcDz9reFhYsPZ
Ohl+hLGZGwDFGguCdJ4lUJRix9sncVcljd2pnDmOjCBPZV+V2vf3h9bGCE6u9uo05RAaWzVN
d+NWIXiC3CEZNd4ksdMdRv9dX2VPMYIDOzCCAzcCAQEwaTBiMQswCQYDVQQGEwJaQTElMCMG
A1UEChMcVGhhd3RlIENvbnN1bHRpbmcgKFB0eSkgTHRkLjEsMCoGA1UEAxMjVGhhd3RlIFBl
cnNvbmFsIEZyZWVtYWlsIElzc3VpbmcgQ0ECAw7NrTAJBgUrDgMCGgUAoIIBpzAYBgkqhkiG
9w0BCQMxCwYJKoZIhvcNAQcBMBwGCSqGSIb3DQEJBTEPFw0wNjA1MjMyMjA2MTNaMCMGCSqG
SIb3DQEJBDEWBBRAR15N5M0zyt62KtHaG8m0SP7AFDBSBgkqhkiG9w0BCQ8xRTBDMAoGCCqG
SIb3DQMHMA4GCCqGSIb3DQMCAgIAgDANBggqhkiG9w0DAgIBQDAHBgUrDgMCBzANBggqhkiG
9w0DAgIBKDB4BgkrBgEEAYI3EAQxazBpMGIxCzAJBgNVBAYTAlpBMSUwIwYDVQQKExxUaGF3
dGUgQ29uc3VsdGluZyAoUHR5KSBMdGQuMSwwKgYDVQQDEyNUaGF3dGUgUGVyc29uYWwgRnJl
ZW1haWwgSXNzdWluZyBDQQIDDs2tMHoGCyqGSIb3DQEJEAILMWugaTBiMQswCQYDVQQGEwJa
QTElMCMGA1UEChMcVGhhd3RlIENvbnN1bHRpbmcgKFB0eSkgTHRkLjEsMCoGA1UEAxMjVGhh
d3RlIFBlcnNvbmFsIEZyZWVtYWlsIElzc3VpbmcgQ0ECAw7NrTANBgkqhkiG9w0BAQEFAASC
AQCF1PVgzwUU0Lon06Q5aoc1hN5PMB4BCS4Xet5YX/0RZxdGtrdYKJraXLw1GcBlw5PgIvZ1
eKBYHT8Jr0HPSLxG+O/mucmDjffK5Ufg7qACs2pizgrPTZt5FPSdgd2iqYS/2rYLMS/BOAC7
ApCsJni0sIo0Dx4DKPKeh7wN3FnujD47VTMeaYLgOqZySQad/BNjLiLxrP7Jd+DSUUk6ViqE
vlfELj9Kwb/uPVTfhfQbzrqpVnfVuKCsPp2NRBikkvOkUDiFErxF6IAK17TiiSH7DN8FfOrZ
7q3dvFLGhnVTs87ib/cLuKnXAkmiDZkScFtNlvfHEaSSCgoc0Vggl/gpAAAAAAAA
--------------ms020209060004010408070108--