Logging Tools

[Guest]

Hi,

We're running Windows XP SP2 workstations, in a Windows 2003 domain. Some of
our users are reporting very slow logon times, between 5 - 10 minutes after
they enter their username/password till when the desktop loads, and they can
actually start working (although bootup seems to be pretty quick, about 1
min from turning the PC on until the login screen). Does anyone have any
good logging tools, that I can use to see what's going on while the user is
logging on?

Cheers

Ben

 

[q_q_anonymous]

Hi,

We're running Windows XP SP2 workstations, in a Windows 2003 domain. Some of
our users are reporting very slow logon times, between 5 - 10 minutes after
they enter their username/password till when the desktop loads, and they can
actually start working (although bootup seems to be pretty quick, about 1
min from turning the PC on until the login screen). Does anyone have any
good logging tools, that I can use to see what's going on while the user is
logging on?

Cheers

Ben

bootlogxp
http://greatis.com/utilities/bootlogxp/

 

[Wesley Vogel]

Start | Run | Type: msconfig | Click OK |
Boot.ini tab | Select: /BOOTLOG | Click Apply | Click OK

/bootlog = Enables boot logging to a file called %systemroot%\Ntbtlog.txt.

C:\WINDOWS\Ntbtlog.txt

/BOOTLOG - This option tells Windows XP to log everything it does during the
boot process to the c:\windows\ntbtlog.txt file. This can be useful for
diagnosing startup problems by seeing exactly where the boot process is
hanging.

Note
[[In safe mode, new boot log entries are appended to the existing
Ntbtlog.txt file.]]

From XP HELP:
Startup options
Enable Boot Logging
[[Starts while logging all the drivers and services that were loaded (or not
loaded) by the

system to a file. This file is called ntbtlog.txt and it is located in the
%windir% directory. Safe

Mode, Safe Mode with Networking, and Safe Mode with Command Prompt add to
the boot log a

list of all the drivers and services that are loaded. The boot log is useful
in determining the exact

cause of system startup problems.]]

--
Hope this helps. Let us know.

Wes
MS-MVP Windows Shell/User

In

 

[Guest]

bootlogxp
http://greatis.com/utilities/bootlogxp/

Thanks for the link, looks like a good app, I like the timeline graph
showing how long each process ran. I will test it out tomorrow on the slow
workstations.

Cheers

Ben

 

[Vincent Xu [MSFT]]

Hi Ben,

I think you can also find some clues from UserEnv log. However, UserEnv log
is not enabled by default, please follow the steps as below to enable it:

Warning If you use Registry Editor incorrectly, you may cause serious
problems that may require you to reinstall your operating system. Microsoft
cannot guarantee that you can solve problems that result from using
Registry Editor incorrectly. Use Registry Editor at your own risk.
Use Registry Editor to add the following registry value (or modify it, if
the value already exists):
Key: HKEY_LOCAL_MACHINE\Software\Microsoft\Windows
NT\CurrentVersion\Winlogon
Value: UserEnvDebugLevel
Value Type: REG_DWORD
Value Data: 10002 (Hexadecimal)

UserEnvDebugLevel can have the following values:
NONE 0x00000000
NORMAL 0x00000001
VERBOSE 0x00000002
LOGFILE 0x00010000
DEBUGGER 0x00020000

The default value is NORMAL|LOGFILE (0x00010001).

Note To disable logging, select NONE (where the value is 0X00000000).

You can also combine the values. For example, you can combine VERBOSE
0x00000002 and LOGFILE 0x00010000 to get 0x00010002. So if
UserEnvDebugLevel is set with a value of 0x00010002, this turns on both
LOGFILE and VERBOSE. Combining these values is the same as using an OR
statement: 0x00010000 OR 0x00000002 = 0x00010002

The log file is written to the %Systemroot%\Debug\UserMode\Userenv.log
file. If the Userenv.log exists and is greater than 300 KB, the existing
file will be renamed to Userenv.bak, and a new log file created.

If you didn't find any clues, you can also send me the log, I'll try my
best to be of assistance. My email is: (e-mail address removed)

Have a good day.


Best regards,

Vincent Xu
Microsoft Online Partner Support

======================================================
Get Secure! - www.microsoft.com/security
======================================================
When responding to posts, please "Reply to Group" via your newsreader so
that others
may learn and benefit from this issue.
======================================================
This posting is provided "AS IS" with no warranties,and confers no rights.
======================================================



--------------------

 

[Guest]

Hi Vincent,

Thanks for the great reply! I will enable logging on the users workstation
now, and give it a test. I will post back my finding when done.

Cheers

Ben

 

[Guest]

Hi Vincent,

Hopefully you got my email, and it wasn't captured by a spam filter or
anything. If not, let me know, and I'll send again.

Cheers

Ben

 

[Vincent Xu [MSFT]]

Hi,

I think it apperas to be caused by Slow link detection. Try following
article:

How to force Kerberos to use TCP instead of UDP in Windows Server 2003, in
Windows XP, and in Windows 2000
http://support.microsoft.com/?id=244474


Best regards,

Vincent Xu
Microsoft Online Partner Support

======================================================
Get Secure! - www.microsoft.com/security
======================================================
When responding to posts, please "Reply to Group" via your newsreader so
that others
may learn and benefit from this issue.
======================================================
This posting is provided "AS IS" with no warranties,and confers no rights.
======================================================



--------------------

 

[Guest]

Hi Vincent,

I made those changes, and added the suggested adm template to our group
policy, but I'm still getting complaints about slow start up times this
morning. I ran the bootlogxp utility 3 times on a workstation, and found
that 4 particular processes, System, spoolsv, svchost & winlogon, take a
long time to start, I have c+p them below, snipping out some of the data to
save room. I have marked the points at which the process seems to jump up a
huge step.
One question I'm not sure of is, in the following example there is a huge
jump between msi.dll and kbduk.dll, does this means that msi.dll took a long
time to start, and the system had to wait to load kbduk.dll, or that msi.dll
loaded quickly, but kbduk.dll to a long time to load, before it could be
started?
C:\WINDOWS\system32\msi.dll Start: 49.211 sec
C:\WINDOWS\system32\kbduk.dll Start: 325.466 sec <--Big jump from 49 to 325
seconds

log file from bootlogxp below

Path: System
Start: 8.645 sec Duration: 322.989 sec
ID: 4 18.05.2006 09:39:05.493
DLL's:
C:\WINDOWS\system32\DRIVERS\intelppm.sys Start: 8.645 sec
C:\WINDOWS\system32\DRIVERS\CmBatt.sys Start: 8.65 sec
C:\WINDOWS\system32\DRIVERS\VIDEOPRT.SYS Start: 8.665 sec
C:\WINDOWS\system32\DRIVERS\nv4_mini.sys Start: 8.668 sec
C:\WINDOWS\system32\DRIVERS\USBPORT.SYS Start: 8.671 sec
C:\WINDOWS\system32\DRIVERS\usbuhci.sys Start: 8.673 sec
<snip>
C:\WINDOWS\system32\DRIVERS\wanarp.sys Start: 26.615 sec
C:\WINDOWS\system32\DRIVERS\arp1394.sys Start: 26.639 sec
C:\WINDOWS\system32\Drivers\Cdfs.SYS Start: 27.657 sec
C:\WINDOWS\system32\DRIVERS\irda.sys Start: 40.849 sec <--Big jump from 27
to 40 seconds
C:\WINDOWS\system32\DRIVERS\ndisuio.sys Start: 40.869 sec
C:\WINDOWS\system32\drivers\pmemnt.sys Start: 49.195 sec
C:\PROGRA~1\COMMON~1\SYMANT~1\VIRUSD~1\20060517.020\navex15.sys Start:
68.881 sec
C:\PROGRA~1\COMMON~1\SYMANT~1\VIRUSD~1\20060517.020\naveng.sys Start: 68.887
sec
C:\PROGRA~1\COMMON~1\SYMANT~1\VIRUSD~1\20060517.020\navex15.sys Start:
70.643 sec
C:\PROGRA~1\COMMON~1\SYMANT~1\VIRUSD~1\20060517.020\naveng.sys Start: 69.799
sec
C:\WINDOWS\system32\drivers\wdmaud.sys Start: 331.008 sec <--Big jump from
69 to 331 seconds
C:\WINDOWS\system32\drivers\sysaudio.sys Start: 331.049 sec
C:\WINDOWS\system32\drivers\splitter.sys Start: 331.107 sec
C:\WINDOWS\system32\drivers\aec.sys Start: 331.131 sec
C:\WINDOWS\system32\drivers\swmidi.sys Start: 331.178 sec
C:\WINDOWS\system32\drivers\DMusic.sys Start: 331.555 sec
C:\WINDOWS\system32\drivers\kmixer.sys Start: 331.593 sec
C:\WINDOWS\system32\drivers\drmkaud.sys Start: 331.625 sec



Path: G:\WINDOWS\system32\svchost.exe
Start: 41.144 sec Duration: 318.123 sec
ID: 1264 18.05.2006 09:39:37.742
DLL's:
G:\WINDOWS\system32\svchost.exe Start: 41.144 sec
C:\WINDOWS\system32\ntdll.dll Start: 41.144 sec
C:\WINDOWS\system32\kernel32.dll Start: 41.145 sec
C:\WINDOWS\system32\advapi32.dll Start: 41.145 sec
C:\WINDOWS\system32\rpcrt4.dll Start: 41.145 sec
<snip>
C:\WINDOWS\system32\ipconf.tsp Start: 65.547 sec
C:\WINDOWS\system32\h323.tsp Start: 65.59 sec
C:\WINDOWS\system32\hidphone.tsp Start: 65.615 sec
C:\WINDOWS\system32\hid.dll Start: 65.627 sec
C:\WINDOWS\system32\rasppp.dll Start: 65.796 sec
C:\WINDOWS\system32\ntlsapi.dll Start: 65.809 sec
C:\WINDOWS\system32\msxml3.dll Start: 98.561 sec <--Big jump from 65 to 98
seconds
C:\WINDOWS\system32\apphelp.dll Start: 99.517 sec
C:\WINDOWS\system32\wups.dll Start: 100.678 sec
C:\WINDOWS\system32\rasadhlp.dll Start: 104.501 sec
C:\WINDOWS\system32\wbem\ncprov.dll Start: 120.661 sec
C:\WINDOWS\system32\wbem\wbemcons.dll Start: 120.789 sec
C:\WINDOWS\system32\actxprxy.dll Start: 339.895 sec <--Big jump from 120 to
339 seconds
C:\WINDOWS\system32\wbem\wbemcons.dll Start: 349.319 sec
C:\WINDOWS\system32\upnp.dll Start: 351.185 sec
C:\WINDOWS\system32\ssdpapi.dll Start: 350.901 sec
C:\WINDOWS\system32\rasdlg.dll Start: 354.098 sec
C:\WINDOWS\system32\wbem\wbemprox.dll Start: 359.391 sec


Path: G:\WINDOWS\system32\winlogon.exe
Start: 34.329 sec Duration: 301.185 sec
ID: 832 18.05.2006 09:39:31.335
DLL's:
G:\WINDOWS\system32\winlogon.exe Start: 34.329 sec
C:\WINDOWS\system32\ntdll.dll Start: 34.329 sec
C:\WINDOWS\system32\kernel32.dll Start: 34.329 sec
C:\WINDOWS\system32\advapi32.dll Start: 34.331 sec
<snip>
C:\WINDOWS\system32\dnsapi.dll Start: 48.241 sec
C:\WINDOWS\system32\appmgmts.dll Start: 49.21 sec
C:\WINDOWS\system32\msi.dll Start: 49.211 sec
C:\WINDOWS\system32\kbduk.dll Start: 325.466 sec <--Big jump from 49 to 325
seconds
C:\WINDOWS\system32\fdeploy.dll Start: 327.663 sec
C:\WINDOWS\system32\clbcatq.dll Start: 327.987 sec
C:\WINDOWS\system32\comres.dll Start: 327.989 sec
C:\WINDOWS\system32\wbem\wbemprox.dll Start: 327.994 sec
C:\WINDOWS\system32\wbem\wbemcomn.dll Start: 327.994 sec
C:\WINDOWS\system32\xpsp2res.dll Start: 328.032 sec
<snip>
C:\WINDOWS\system32\NavLogon.dll Start: 335.685 sec
C:\WINDOWS\system32\es.dll Start: 335.699 sec


Path: G:\WINDOWS\system32\spoolsv.exe
Start: 46.961 sec Duration: 318.623 sec
ID: 536 18.05.2006 09:39:43.651
DLL's:
G:\WINDOWS\system32\spoolsv.exe Start: 46.961 sec
C:\WINDOWS\system32\ntdll.dll Start: 46.961 sec
C:\WINDOWS\system32\kernel32.dll Start: 46.961 sec
C:\WINDOWS\system32\advapi32.dll Start: 46.963 sec
<snip>
C:\WINDOWS\WinSxS\x86_Microsoft.Windows.Common-Controls_6595b64144ccf1df_6.0.2600.2180_x-ww_a84f1ff9\comctl32.dll
Start: 46.999 sec
C:\WINDOWS\system32\comctl32.dll Start: 47.018 sec
C:\WINDOWS\system32\spoolss.dll Start: 114.835 sec <--Big jump from 47 to
114 seconds
C:\WINDOWS\system32\ws2_32.dll Start: 114.843 sec
C:\WINDOWS\system32\ws2help.dll Start: 114.845 sec
C:\WINDOWS\system32\mswsock.dll Start: 114.855 sec
<snip>
C:\WINDOWS\system32\comres.dll Start: 120.199 sec
C:\WINDOWS\system32\xpsp2res.dll Start: 120.241 sec
C:\WINDOWS\system32\inetpp.dll Start: 120.71 sec
C:\WINDOWS\system32\dlbkpwr.dll Start: 121.118 sec
C:\WINDOWS\system32\spool\drivers\w32x86\3\KRH36G2.dll Start: 357.768 sec
<--Big jump from 121 to 357 seconds
C:\WINDOWS\system32\spool\drivers\w32x86\3\DKAAP2DD.DLL Start: 365.208 sec

 

[Vincent Xu [MSFT]]

Hi,

I'll check the information you newly provided. Meanwhil, I have following
suggestions:

- NIC driver (timing issue) ¨C> apply latest NIC drivers /
multihomed PCs (including wireless NICs)
- NIC / Switch settings (i.e. Intel PROset used, InterfaceMetric
setting)
- Spanning Tree and PORTFAST settings on the switches,
- GPO "Always wait for the network at computer startup and logon" policy
on the clients
- DisableDHCPMediaSense settings on the clients
- Additional Services on the clients introduced (Personal Firewall, ..)

There is a second (quite new) reg. key that also may positive influence the
behaviour:
GpNetworkStartTimeoutPolicyValue
The "GpNetworkStartTimeoutPolicyValue" policy timeout can be specified in
the registry in two locations:

- HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows NT\Current Version\Winlogon
or
- HKEY_LOCAL_MACHINE\SOFTWARE\Policies\Microsoft\Windows\System (<-will
take precedence)


Description: Time entered specifies the maximum time in seconds we will
wait for the network to become available. (we are trying the entire time)
Value: number of seconds between 30 and 600.

For more information please see KB article KB840669
840669 Group Policy application fails on a computer that is running Windows
http://support.microsoft.com/?id=840669


Hope this helps.

Best regards,

Vincent Xu
Microsoft Online Partner Support

======================================================
Get Secure! - www.microsoft.com/security
======================================================
When responding to posts, please "Reply to Group" via your newsreader so
that others
may learn and benefit from this issue.
======================================================
This posting is provided "AS IS" with no warranties,and confers no rights.
======================================================



--------------------