Troubleshooting User Profile Problems on Vista and Server 2008 - But How?
- User Profiles
- Published Oct 23, 2008 Updated Feb 22, 2021
User profile problems are among the most common support issues. It is only appropriate that Microsoft simplified the troubleshooting process over time - but forgot to port it over to Vista.
How it was
While on NT 4 userenv.dll had to be replaced with a so-called checked (i.e. debug) version in order to generate a log file. On Windows 2000, XP and Server 2003 verbose debug output can be enabled by setting the following registry value:
HKEY_LOCAL_MACHINE\Software\Microsoft\Windows NT\CurrentVersion\Winlogon\UserEnvDebugLevel=10002 [REG_DWORD, hex]
This causes Windows to write detailed status messages to the log file %Systemroot%\Debug\UserMode\Userenv.log. Not even a reboot is required.
Although the messages written to userenv.log are difficult to interpret the file is invaluable when it comes to troubleshooting user profile problems since it is the only source of information.
How it is
One would assume that in a new OS version Microsoft would address the difficult to interpret problem. They did - in a way. As they moved the user profile code from userenv.dll to the new User Profile Service they simply dropped logging altogether! Only very few messages are logged to the event log instead. The net effect: diagnosing profile problems on Vista and Server 2008 is a frustrating trial and error job.
Addendum 1
According to Steve Patrick, user environment debug logging has been replaced by ETW logging in Vista (and, subsequently, Server 2008). Unfortunately the “logs” generated are of no use to anyone outside Microsoft. I tried out what Steve suggests on a Server 2008 machine with Terminal Services installed. In an admin session, I configured the trace and then logged on as a user and back off immediately. After stopping the trace a 24 KB ETL file was generated, which I converted to a 86 KB CSV file. Here are the commands I used:
C:\temp>logman -start profiletrace -p {eb7428f5-ab1f-4322-a4cc-1f1a9b2c5e98} 255 3 -ets
C:\temp>logman -stop profiletrace -ets
C:\temp>tracerpt ProfileTrace.etl -y -of csv -o "Profile Trace.csv"
The CSV file contains the following data (excerpt):
Event Name, Type, Event ID, Version, Channel, Level, Opcode, Task, Keyword, PID, TID, Processor Number, Instance ID, Parent Instance ID, Activity ID, Related Activity ID, Clock-Time, Kernel(ms), User(ms), User Data
EventTrace, Header, 0, 2, 0, 0, 0, 0, 0x0000000000000000, 0x00000000, 0x00000A74, 0, , , {00000000-0000-0000-0000-000000000000}, , 128770914082864420, 480, 0, 8192, 67174406, 6001, 1, 128770916985312337, 156250, 0, 0x0, 3, 1, 4, 0, 2095, 0xA3857178, 0xA3857192, 128681216915000000, 3579545, 128770914082864420, 0x1, 0, "profiletrace", "C:\temp\profiletrace.etl"
Unknown, 10, 10, 144, 0, 0, 0, 0, 0x0000000000000000, 0x00000770, 0x00000A1C, 0, , , {00000000-0000-0000-0000-000000000000}, , 128770914521470829, 0, 0, "Unknown", "", "GUID=147d65d9-40d4-7085-0f6d-f09272c92f78 (No Format Information found).", "", "", {147d65d9-40d4-7085-0f6d-f09272c92f78}, " 10", "", 0, "", "", "1601-01-01T00:00:00.000000000Z", {00000000-0000-0000-0000-000000000000}
Unknown, 10, 10, 144, 0, 0, 0, 0, 0x0000000000000000, 0x00000EA0, 0x00000FE4, 0, , , {00000000-0000-0000-0000-000000000000}, , 128770914951024395, 0, 0, "Unknown", "", "GUID=147d65d9-40d4-7085-0f6d-f09272c92f78 (No Format Information found).", "", "", {147d65d9-40d4-7085-0f6d-f09272c92f78}, " 10", "", 0, "", "", "1601-01-01T00:00:00.000000000Z", {00000000-0000-0000-0000-000000000000}
Unknown, 10, 10, 144, 0, 0, 0, 0, 0x0000000000000000, 0x00000760, 0x00000720, 0, , , {00000000-0000-0000-0000-000000000000}, , 128770915030645462, 0, 0, "Unknown", "", "GUID=147d65d9-40d4-7085-0f6d-f09272c92f78 (No Format Information found).", "", "", {147d65d9-40d4-7085-0f6d-f09272c92f78}, " 10", "", 0, "", "", "1601-01-01T00:00:00.000000000Z", {00000000-0000-0000-0000-000000000000}
Unknown, 10, 10, 144, 0, 0, 0, 0, 0x0000000000000000, 0x0000097C, 0x00000E70, 0, , , {00000000-0000-0000-0000-000000000000}, , 128770915120968944, 0, 0, "Unknown", "", "GUID=147d65d9-40d4-7085-0f6d-f09272c92f78 (No Format Information found).", "", "", {147d65d9-40d4-7085-0f6d-f09272c92f78}, " 10", "", 0, "", "", "1601-01-01T00:00:00.000000000Z", {00000000-0000-0000-0000-000000000000}
...
One might wonder if the GUID given by Steve is correct and where he got it from. Issuing “logman query providers” yields a long list of available ETW providers, from which the following two entries look promising:
Microsoft-Windows-User Profiles General {DB00DFB6-29F9-4A9C-9B3B-1F4F9E7D9770}
Microsoft-Windows-User Profiles Service {89B1E9F0-5AFF-44A6-9B44-0A07A7CE5845}
Using these providers, the ETL file remains empty, though.
Addendum 2
According to an article on the AskDS blog, Windows 7 still has no real replacement for UserEnv.log. The only way to debug profile load issues is to create a binary ETL log that then needs to be analyzed by Microsoft. Not very satisfactory.
Comments