[OpenAFS-win32-devel] Slow Windows logins with AFS installed
Ted Anderson
ota@surfvi.com
Wed, 01 Feb 2006 23:34:21 -0400
This is a multi-part message in MIME format.
--------------010202050908090907050709
Content-Type: text/plain; charset=us-ascii; format=flowed
Content-Transfer-Encoding: 7bit
Ted Anderson wrote:
>> On 02/01/2006 03:01, Jeffrey Altman wrote:
>>>> If you are seeing delays after you know the AFS Client Service is
>>>> running, then please turn on logging for the Integrate Login
>>>> functionality and send the Event Log output to
>>>> openafs-bugs@openafs.org.
>
>> I reinstalled to set things back they way they were, set the various
>> registery keys to enable more tracing, then reproduced the delays. I
>> now have an event log with lots of AFS traffic in it. How do I get
>> "the Event Log output", in a file so I can send it to you. I don't
>> want to send the whole .evt file as that has lots of other events
>> from the rest of the system that I'd rather not publish. I couldn't
>> find a built in tool to get the output in any reasonable format. I
>> downloaded log parser, but it is a hairball.
>>
>> Are you only interested in AFS Logon events, or are AFS Client and
>> TransarcAFSDaemon entries also of interest?
>
> The Event Log Viewer has a Filter function and a Save As ... function.
> Please export all AFS related events and please do not send e-mail to
> me personally. Please keep discussions in public forums. Either on
> a mailing list or in the bug tracker so that others can gain from your
> experience.
The Event Log Viewer only seemed to know how to export the whole log,
even with filtering turned on. I eventually got LogParser to do
something useful (I used v2.0, but v2.2 is available[2]), so I ran the
following command:
% logparser -e 3 -i:evt -o:nat "select TimeGenerated, SourceName,
Strings from application to c:/temp/afs-logon.txt where SourceName =
'AFS Logon' or SourceName = 'AFS Client' or SourceName =
'TransarcAFSDaemon'" -ignoremsgerr ON
I cleaned up the output a bit, compressed it and have attached it to
this message as afs-logon.txt.gz.
I reinstalled the OpenAFS client from the 1.4.1rc5 (non-debug) bits and
configured it by deselecting all the integrated logon features. I used
RegEdit to turn on extra tracing. I verified with Spybot - search and
destroy, that AfsLogon and KFWLogon were reattached to afslogon.dll in
System.ini as reported earlier[1]. Then I rebooted at about 20:30.
Here is the approximate timeline according to my notes:
20:40 After the system came up, I verified that AFS worked in my home
cell inside the VPN.
20:43:30 touched a file.
20:44:30 logout, completed in 10-15 seconds
20:45:03 login, "applying your personal settings..."
20:46:08 dialog boxes about failing to restore SMB connections.
20:46:22 desktop displayed
Did not restart the VPN. Instead listed the public directory
//afs/sipb.mit.edu/contrib/wedding. All okay.
21:00:00 logout
21:00:10 login dialog appears
21:01:00 login, applying settings...
21:02:00 problems restoring SMB shares:, hit OK button several times.
21:02:20 desktop, listing above directory in sipb.mit.edu still works.
The SMB problem is due to the wireless card not being configured for
NetBUI. I disabled the wireless card, and logged out and back in and
got the same 60 second delay, so I don't think it is relevant to this
problem.
Let me know if I can provide more helpful details about my configuration
or environment..
Ted Anderson
[1]
http://lists.openafs.org/pipermail/openafs-win32-devel/2006-January/000399.html
[2]
http://www.microsoft.com/downloads/details.aspx?FamilyID=890cd06b-abf8-4c25-91b2-f8d975cf8c07
On 01/31/2006 20:42, Ted Anderson wrote:
> On 01/26/2006 22:42, Jeffrey Altman wrote:
>> Ted Anderson wrote:
>>> I don't believe this explanation applies to my case. My AFS client
>>> service is configured to start at boot time. I do not use a roaming
>>> profile and none of my profile stuff is stored in AFS. The delay I
>>> am seeing occurs when logging in and out without rebooting, and
>>> while using AFS just fine both before logging out and after logging
>>> back in.
>>
>> I am explaining to you how the code is written. If the AFS Client
>> Service has not started when you log in, the login will not complete
>> until it does.
>
> It would seem that this would delay the first login after booting the
> system, assuming the AFS is configured to start a boot time, which I
> do. But it does not seem like it would affect subsequent log ins.
> Yet, it is slow logins long after the system has booted and AFS is
> running correctly that I am referring to.
>
>> This has nothing to do with roaming profiles. Let us imagine a local
>> profile that accesses a resource stored in AFS. For example, an
>> update to the anti-virus dictionary. The purpose of this
>> functionality is to ensure that if AFS is installed on the machine
>> that AFS is functional when the user logs in. Not after the user
>> logs in.
>
> Do you mean to say that the code "ensures" "that AFS is functional"
> every time some one logs in? What type of checks does it do?
>
> Ted
>
>> If you would like to avoid this behavior you can set AFS for manual
>> start and activate it when you require it.
>>
>>> Right, this is part of the reason why I have enabled the freelance
>>> client. With freelance, the configuration of the default cell seems
>>> to have little functional impact, but does provide the convenience
>>> of not having to specify a cell when running klog and pts commands.
>>>
>>> Once I get logged in and start the VPN, AFS works just fine, both
>>> with and without the registery settings I needed to alter. Based on
>>> this, my suggestion is that these settings should automatically be
>>> removed when "Obtain AFS tokens when logging into Windows" is NOT
>>> checked.
>>
>> All this means is that by the time the VPN has been started, the AFS
>> Client Service has been started by Windows.
>>
>> Jeffrey Altman
--------------010202050908090907050709
Content-Type: application/x-gzip;
name="afs-logon.txt.gz"
Content-Transfer-Encoding: base64
Content-Disposition: inline;
filename="afs-logon.txt.gz"
H4sICO1z4UMCA2Fmcy1sb2dvbi50eHQA7V1bb9s4Fn4v0P9ADLBoA8QJKYq6AbtAJukNkybF
JLvz4DEKxaITIbLkleSm2V+/pGQn1sUWKZFuphijD25jft+58ZDn6MT9B4iS24WfZjQFIwow
GIUe/ZaDUeLFfg5+yWhEpzm4Duf0A41p6uc0OARXyTKd0gt/Ttn7PA3j2wzM0mQO/MUiCqd+
HiYxyBMw9Y5zOl8c+7NsxHiS+Cj/noOHO5rSDQzwT/Dm5P0VOOefeAOStOVnp1FI47zlh9ep
H2d+OmUfOvPpnAH8wnS4jZOUzrNbmqbg8uL1q9evKhqA8rWBtNai1+v1q1HzBVrfyr8YOjKO
ET42ICQAEc9gfxB4NkrxNsv9NAcLGgdMDSnRm+BuHTxdxrEcbAu4YXgEeYazCf7lPmeSp34Q
RMwpGc0yHjiFLsvFIYug5B6Y0IUWmGeHIJ7egIjGt/kdcMw2cAw3wafzryexHz3+j3rgo58G
Z9QPeBQA+n1KaUCDIynJq+AikiNkGciti+7iBrhRs7mQWbDt2g2zOEAJuGO32NzFK3BzFS3I
g4YHzXq0/HcZ5nmPcGkDd9XGeQUcYbVxvga3PcPyMN5plsYK1yPmTl3rKzBkOuxUoFxhr1Y4
HgsGbAtwVFaYRIqD4BY9WjSvriBSUvEVjrhUBi52ryXOUa4Q0txZrWDOwOyP2mitgCNTabQa
5ClDQLvLA0PAHQ8SpZJj9HRYIYs5Sqnkm+C2B6FCyY8LaIu7E5k8HoFCyavgLHSBSsnNEpyn
TRYrbhVc7CSEDjv5awcKcWvgTkNyEXALQ7sFG7Td+eRufC33OrlbXc16LHlhR87rDQDTkvNs
FcBkucSWuyRtAmDPxC3HjrgKBQBC/VVgqRkyjCESMACCe0tglDawe0tQAqAebiQrAKPY4z0k
qAAQC3QdcMdWucDmW5Pdf0HXGVpd4IJuBvspbxHXY5flTobKApZTOhmcZ6XtQokuhuoCt5vB
fVpgmPxW2clQWWDgbgYEn2IHI4FbXG1BM1a6g40f4wUCyzqo63LaidBWJwjIgFeblgUTbkEQ
kKGCgHpse0SeA475C/aQoYKAYQ8ZVkHPzGjaLfcpARkqCKiHL4xV+nLZCeQZBMgeIi39F53t
F5Xdl526CzYCbAIb9bRbw7Z5X0e6VDdc3OgDIIgLbPIc/Sx2LYWVegWbpUmVBUQN21RZp29i
M2eauuRm2ESX3MRsySKK5ObYrlK5nedTwJW+O8pgy14rd2Pj1QnKakzEiipHfs+biKWK1pJn
E5sd50jlvqxim0rtXcO21Nnb2ChgDcLNrc4mm9gY8jABT08birdfr0rPfX33jbMNwbYUFvU1
bMMEeuyN+R2xYpOLL8WbiyQPZ49gxP85jD8Fb+Ehck2DkANJ7A3oTzH4QPOzZO6HcfFPlwv+
sCgDsyQFS/4Uapzk/gSEMQiKD4Hxyfnlx8vPl7+fTDqwW4E9cOrHb3KQMBeA8scZuKePYGxM
JORmtigguLlXgnEQLvX4/PL05Pzj5dX1pJ9NkkU++teGzAx1GQfcBHf3FwvwELLEkT8uKBib
E1ns4OFsOZ8/ghvKJc9ozh/LBXTmL6O8V5zU5U5pnj5+inOafvMjCRoR7CyidKEe+wPzZfE0
EmTTNFzkHngbL6PooPfe2cDecOMYTg7BFZM9nFJwssyTIs2M0aQvNn97MsvKv43ANc3yJ/zf
u1LB8G6YzkbZ7hv4Tqs83IURfesz+xap9kDKBXot3i03i8Nkwcqk8PmhtIoorMn9juGrxP5a
vF0dlyNQGFUL9pc0mbLbFfh05gHDgoOwy9zvgafjRKG9eUa5+nTGL4U8JMZXIzQiIwONELIt
6NoIjpAFTcNAtm2NbINgkxATjxCEqHmqrS5W65OHbc9iyCFi+5adn8yVH07BzA/53XPMSEwb
GpiYrXmlhm16EHVgl2YSwW9gI6vN3v1fHQSDjN5OUPXqb+//6B/p/QiKvwnetHoRvIuDYT7A
SFlwthN0Rr94hIoQNNMZSzoznprPwpRO8yR9ZFdI78+zZLqcsw9kwGcmvKJFMZL9yS6r0gTl
D7hmG9mII0maaFUJXH3+tVmDQpDEtwnfF8kik3YyI2jMVYFv0wWA313HsYIbB0R+7AMCoiwG
SMnmbuU8TQLKSCFQ8mpy2j9AT3u7npbFEpRh3Py0ev7n9Mt4xTgBMX0YLcOAX8dithnGEz2c
n/17ekEf/s2KS2+T//CcqTwmk0OmM5PhkFefhTSH1+H0nua/XZ/yPTr2o+QumSepz7foRMqf
P33cVh1a1K0Vl1Zt1825s0ZZT20OKlW6yxUlVUtb5aIrVtpoNg6g1at5Dv1xQfOTIDhN4pgd
dOz4MN4egGw5LZ/ZKKORvHJUacyiqaYh2MVoBuflF6VNa/aFEtlXjEYy4cJ6wp1I+UbVvvnB
vtmWSdvd8/rV0dERmEXL7I7t1CiMaeZtt5DYp7crKrZe7iwQlukZMirDB5ThUzOruR65bU9H
s5lIEdcbc0eOq2GS9ZhoZ6+dGI5NnAOJ0CLrGQn1zfYGtsJmewNbYbO9ga2w2d7AVthsb5db
TbO9HVtNs70ZJ+qa7Q3sgc32n6Mh3rCKwqZ1A1ths33/cqtptnfJPaTZ3oatqtneiT2g2d7A
Vthsb80oiprtDBu5mprtDBubOluZjMB0dXbcGwSqO+6mVXOt6o67AMFzx13gvtVNoLohLqDB
sJY+I+jcAsPCtE6guuMuQDCs414SKG0OiBFUCqpVKTX38+ndqLO5JkbwPowDXqb/+ljYZmtD
NO7qgzZ8MLzp1Jdg13aoYRa/+DbUr2KYDVfCiisnfTCFvAdX3puIYcq2IfbQsN1Ht7bF4pVn
bGtN2HWUVc3IcI6MI4SPkOuClC6SlCv/LYlYvgIEW44NXWQBPwMxOzH9PPend8UQfIXDqU3D
auKw9XOgPehRncDVw2HgPXDsQQ9s7oWjK3M6w26fTm0SXY8e1d8A0MNBtMeVu4dc4noI7oHD
2QuH5tgV4rhRgjnoZrEFc9DNYgum7M2ihmnY+uMCE/0cpqmfg+jOBQTWvhtBG4fefco5XP16
IFs/h2Hp59B+r2j8br82DtWP+rVUQjoqHyBmjSGnyjbMIafKNswhp4pQJCAim1F+Hkz4AjAt
/dUl57A0ZAQRDrl91o9j0L6z1Iyr1DFt/T7VXs1zDlc/h/5T19JfaRNLf6VdcqiturZhDjof
t2AO3KcmUb9Pu+2JiBJ7/iUx4YvAJFD/viLa84Nd+34fPRz67xJ27ct5NXG4e+HQXH3bHjY6
94P5EjBN92/Ml45JzL8xXzYm/0bhvwamDt0VYyIPwtqvcw+eeZfCFJ87qlGgdfO4SrF9Et5B
tmOjg+EUygbit1Mom4vfYShV4/EtFL3G4zswe43Fi8gpOw4vgik7Bt+B2Wv8vQOz19h7B2av
4esOzF7D4j9KTtnhcLGtqmw2vKRAQhNwPUfExSl6T4pvp1A2ML6dQtnceEFR/S6SdWZWNT5e
UGAkRtHvK1sKCtPa4YvBI+TbKdROkpf/V0ibtdQOlMvwPM+VC9xehHnUjpfL6DNkyrz871Ys
1dEswaN25lyGZ8jo+ZpHx/eFiPEomkDfTqBoAl3GI70m0GUIhLdKg4AYqktERZj/Bzgf2GYn
bgAA
--------------010202050908090907050709--