[OpenAFS] Windows AFS client initialization delays

[Jeffrey Altman]

This is a cryptographically signed message in MIME format.

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

John Perkins wrote:
> I've been seeing some initialization issues with the 1.5.5X OpenAFS 
> clients recently on some computers we have running in our department.  
> In particular, it seems to take an inordinate amount of time to get the 
> AFS client to a point where it will accept file service requests.  
> 
> This afternoon, I loaded the 1.5.52 client.  The problem I'm seeing
> is that it will take 5-10 minutes before the SMB redirector is willing to 
> serve files on the computer.  afsd_init.log indicates a delay between 
> tweaking the Windows Firewall and logging various preset mountpoints.  
> 
> I've left an "fs trace" log and afsd_init.log in 
> http://pages.cs.wisc.edu/~john/winafs-logs for those who feel they might
> have some insight into this problem (and spare those who don't want to 
> look through lengthy log files).  I'm willing to post them here upon
> request.
> 
> The Windows clients I've been working with lately are running XP SP3,
> if that makes a difference. 
> 
> Any pointers, or even additional debugging requests, would be greatly
> appreciated... 

The suspicious aspect of the logs is this:

time 1.606670, tid 1900 Dispatch return  code 0x6654322b vcp 0x0AEC0100
lana 3 lsn 3
time 1.606670, tid 1900 Dispatch (73)ReceiveV3SessionSetupX duration
262969 ms
time 1.606710, tid 1752 Dispatch return  code 0x0 vcp 0x0AEB3FA0 lana 3
lsn 4
time 1.606710, tid 1752 Dispatch (72)ReceiveNegotiate duration 137547 ms
time 1.606720, tid 1752 SendPacket failure code 8 "session number out of
range"
time 1.606970, tid 1900 Request (73)ReceiveV3SessionSetupX straddled
session startup, took 262969 ms, ncb length 216
time 1.606980, tid 1900 SMB SEND code 6654322B as NT C0000016

There are many entries like this.  The SMB client is requesting
authentication in order to setup a new SMB Session.  The authentication
request within Windows is getting stuck and is not returning for greater
than 45 seconds.  As a result the SMB client gives up and terminates the
connection.  afsd_service therefore receives a "session number of of
range" errors when attempting to send the response.

On the 8th attempt the authentication completes in a timely manner.
I would look for network traffic from the box that is not AFS related.
Perhaps a query for a domain controller, a netbios lookup, a dns lookup
or something else that is not getting a response.

---

Note that the native file system client is coming.  When it is here
all of the SMB issues will be gone.





--------------ms090204070501090900030309
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

MIAGCSqGSIb3DQEHAqCAMIACAQExCzAJBgUrDgMCGgUAMIAGCSqGSIb3DQEHAQAAoIIJeTCC
AxcwggKAoAMCAQICEDsE+kRcmomW1hYG6BoqhGEwDQYJKoZIhvcNAQEFBQAwYjELMAkGA1UE
BhMCWkExJTAjBgNVBAoTHFRoYXd0ZSBDb25zdWx0aW5nIChQdHkpIEx0ZC4xLDAqBgNVBAMT
I1RoYXd0ZSBQZXJzb25hbCBGcmVlbWFpbCBJc3N1aW5nIENBMB4XDTA4MDUzMDE5MTUyOVoX
DTA5MDUzMDE5MTUyOVowczEPMA0GA1UEBBMGQWx0bWFuMRUwEwYDVQQqEwxKZWZmcmV5IEVy
aWMxHDAaBgNVBAMTE0plZmZyZXkgRXJpYyBBbHRtYW4xKzApBgkqhkiG9w0BCQEWHGphbHRt
YW5Ac2VjdXJlLWVuZHBvaW50cy5jb20wggEiMA0GCSqGSIb3DQEBAQUAA4IBDwAwggEKAoIB
AQCtf5bVJdYFtHIrV2XALpA5oaMu7FPYU7RP7vJhd8Cu9Kd9ud2crX2pHK4avuPaYb4Vg9qI
zPrPadePhJ3OWwNt1ZlUlpc5URnOfpg/I9iymZBUSnCFVLuIvoncacqyUlzqdYEF8XGEoEL6
6bj8uoCSX0D7ZjZiAS8993NvgiPYpf10acMyWQ4max+P7Wg9T03Nw2F6EsmP6gWxBRsekTXe
N6QjJdvaK0846lDqeBFoCEzIUMQXj2kiXVPCPEdxPc/L1sDMYf0GLaDIg8qyThpGd0X6DwfK
3RWcMy8DV7Q5Z+jSEdPn5X0l4anOTrjr3IwE57MC3bVs0EEpUODTzftnAgMBAAGjOTA3MCcG
A1UdEQQgMB6BHGphbHRtYW5Ac2VjdXJlLWVuZHBvaW50cy5jb20wDAYDVR0TAQH/BAIwADAN
BgkqhkiG9w0BAQUFAAOBgQA9kndmeLrdQOUbhNGGms/FnfDyraH4OjA4PIIMOCbGWK0YXczs
/Fqn4XkT70SG4s8v4Zg6TaAcJrZBVcZQXyzrhlF2Zev/g69zZMHQe+2r4i/3FBVKAtFCoea1
vgwJ5TfZYlKvt4D0Z4zexu9Y0VwCIR4plWjVD76zC2CGB/2fhjCCAxcwggKAoAMCAQICEDsE
+kRcmomW1hYG6BoqhGEwDQYJKoZIhvcNAQEFBQAwYjELMAkGA1UEBhMCWkExJTAjBgNVBAoT
HFRoYXd0ZSBDb25zdWx0aW5nIChQdHkpIEx0ZC4xLDAqBgNVBAMTI1RoYXd0ZSBQZXJzb25h
bCBGcmVlbWFpbCBJc3N1aW5nIENBMB4XDTA4MDUzMDE5MTUyOVoXDTA5MDUzMDE5MTUyOVow
czEPMA0GA1UEBBMGQWx0bWFuMRUwEwYDVQQqEwxKZWZmcmV5IEVyaWMxHDAaBgNVBAMTE0pl
ZmZyZXkgRXJpYyBBbHRtYW4xKzApBgkqhkiG9w0BCQEWHGphbHRtYW5Ac2VjdXJlLWVuZHBv
aW50cy5jb20wggEiMA0GCSqGSIb3DQEBAQUAA4IBDwAwggEKAoIBAQCtf5bVJdYFtHIrV2XA
LpA5oaMu7FPYU7RP7vJhd8Cu9Kd9ud2crX2pHK4avuPaYb4Vg9qIzPrPadePhJ3OWwNt1ZlU
lpc5URnOfpg/I9iymZBUSnCFVLuIvoncacqyUlzqdYEF8XGEoEL66bj8uoCSX0D7ZjZiAS89
93NvgiPYpf10acMyWQ4max+P7Wg9T03Nw2F6EsmP6gWxBRsekTXeN6QjJdvaK0846lDqeBFo
CEzIUMQXj2kiXVPCPEdxPc/L1sDMYf0GLaDIg8qyThpGd0X6DwfK3RWcMy8DV7Q5Z+jSEdPn
5X0l4anOTrjr3IwE57MC3bVs0EEpUODTzftnAgMBAAGjOTA3MCcGA1UdEQQgMB6BHGphbHRt
YW5Ac2VjdXJlLWVuZHBvaW50cy5jb20wDAYDVR0TAQH/BAIwADANBgkqhkiG9w0BAQUFAAOB
gQA9kndmeLrdQOUbhNGGms/FnfDyraH4OjA4PIIMOCbGWK0YXczs/Fqn4XkT70SG4s8v4Zg6
TaAcJrZBVcZQXyzrhlF2Zev/g69zZMHQe+2r4i/3FBVKAtFCoea1vgwJ5TfZYlKvt4D0Z4ze
xu9Y0VwCIR4plWjVD76zC2CGB/2fhjCCAz8wggKooAMCAQICAQ0wDQYJKoZIhvcNAQEFBQAw
gdExCzAJBgNVBAYTAlpBMRUwEwYDVQQIEwxXZXN0ZXJuIENhcGUxEjAQBgNVBAcTCUNhcGUg
VG93bjEaMBgGA1UEChMRVGhhd3RlIENvbnN1bHRpbmcxKDAmBgNVBAsTH0NlcnRpZmljYXRp
b24gU2VydmljZXMgRGl2aXNpb24xJDAiBgNVBAMTG1RoYXd0ZSBQZXJzb25hbCBGcmVlbWFp
bCBDQTErMCkGCSqGSIb3DQEJARYccGVyc29uYWwtZnJlZW1haWxAdGhhd3RlLmNvbTAeFw0w
MzA3MTcwMDAwMDBaFw0xMzA3MTYyMzU5NTlaMGIxCzAJBgNVBAYTAlpBMSUwIwYDVQQKExxU
aGF3dGUgQ29uc3VsdGluZyAoUHR5KSBMdGQuMSwwKgYDVQQDEyNUaGF3dGUgUGVyc29uYWwg
RnJlZW1haWwgSXNzdWluZyBDQTCBnzANBgkqhkiG9w0BAQEFAAOBjQAwgYkCgYEAxKY8VXNV
+065yplaHmjAdQRwnd/p/6Me7L3N9VvyGna9fww6YfK/Uc4B1OVQCjDXAmNaLIkVcI7dyfAr
hVqqP3FWy688Cwfn8R+RNiQqE88r1fOCdz0Dviv+uxg+B79AgAJk16emu59l0cUqVIUPSAR/
p7bRPGEEQB5kGXJgt/sCAwEAAaOBlDCBkTASBgNVHRMBAf8ECDAGAQH/AgEAMEMGA1UdHwQ8
MDowOKA2oDSGMmh0dHA6Ly9jcmwudGhhd3RlLmNvbS9UaGF3dGVQZXJzb25hbEZyZWVtYWls
Q0EuY3JsMAsGA1UdDwQEAwIBBjApBgNVHREEIjAgpB4wHDEaMBgGA1UEAxMRUHJpdmF0ZUxh
YmVsMi0xMzgwDQYJKoZIhvcNAQEFBQADgYEASIzRUIPqCy7MDaNmrGcPf6+svsIXoUOWlJ1/
TCG4+DYfqi2fNi/A9BxQIJNwPP2t4WFiw9k6GX6EsZkbAMUaC4J0niVQlGLH2ydxVyWN3amc
OY6MIE9lX5Xa9/eH1sYITq726jTlEBpbNU1341YheILcIRk13iSx0x1G/11fZU8xggNkMIID
YAIBATB2MGIxCzAJBgNVBAYTAlpBMSUwIwYDVQQKExxUaGF3dGUgQ29uc3VsdGluZyAoUHR5
KSBMdGQuMSwwKgYDVQQDEyNUaGF3dGUgUGVyc29uYWwgRnJlZW1haWwgSXNzdWluZyBDQQIQ
OwT6RFyaiZbWFgboGiqEYTAJBgUrDgMCGgUAoIIBwzAYBgkqhkiG9w0BCQMxCwYJKoZIhvcN
AQcBMBwGCSqGSIb3DQEJBTEPFw0wODA4MjAwMzA0MzNaMCMGCSqGSIb3DQEJBDEWBBTD4x/k
JOnRirB4GRouuDI5mq6DPzBSBgkqhkiG9w0BCQ8xRTBDMAoGCCqGSIb3DQMHMA4GCCqGSIb3
DQMCAgIAgDANBggqhkiG9w0DAgIBQDAHBgUrDgMCBzANBggqhkiG9w0DAgIBKDCBhQYJKwYB
BAGCNxAEMXgwdjBiMQswCQYDVQQGEwJaQTElMCMGA1UEChMcVGhhd3RlIENvbnN1bHRpbmcg
KFB0eSkgTHRkLjEsMCoGA1UEAxMjVGhhd3RlIFBlcnNvbmFsIEZyZWVtYWlsIElzc3Vpbmcg
Q0ECEDsE+kRcmomW1hYG6BoqhGEwgYcGCyqGSIb3DQEJEAILMXigdjBiMQswCQYDVQQGEwJa
QTElMCMGA1UEChMcVGhhd3RlIENvbnN1bHRpbmcgKFB0eSkgTHRkLjEsMCoGA1UEAxMjVGhh
d3RlIFBlcnNvbmFsIEZyZWVtYWlsIElzc3VpbmcgQ0ECEDsE+kRcmomW1hYG6BoqhGEwDQYJ
KoZIhvcNAQEBBQAEggEAO+eiUnSLnDs+rXjvBT/f3VjLrTi7B8k3WIKAYpOj88tLh3KjOYoD
/zkZ0licGPlWbE14WknLumxIsqT87NbOZ/LdVQebchFTamjHa5byC5rIPxSJPrXlSODznXvP
GILdgxw8mxuLeDEUkGMQBsgM0INqs/cnowSYW0Zdt/wp+bnZKoi2svQ4gfB0VYSH/bIFsDJA
ODT5R1zSLuXRtTWlTBz5OZ79kcB7rTCHOpb5nDE+kWLo50GZoPUr+n61HoQlcdJdkoedzIHT
LA1vlqIB9WA2zjR1cIdVx8eI0nRlP5Bll6NX4V+8xnVwbQr2KuML1MeLTiv24AX2VkKzY4Mg
RQAAAAAAAA==
--------------ms090204070501090900030309--