Re: Slow Windows logins with AFS installed

Ted Anderson <[email protected]> Wed, 01 Feb 2006 23:34:21 -0400
Newsgroups gmane.comp.file-systems.openafs.devel.win32
Message-ID <[email protected]>
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
 >>>> [email protected].
 >
 >> 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
afs-logon.txt.gz (application/x-gzip, 2.7 KB) - not displayed