SQL Server Profiler 2008 (or 2008 R2) not showing expected columns for given events while setting up the definition of a new trace

This week, while working in a customer, they showed to me a weird (an somehow inconsistent) experience with SQL Server Profiler. The story was like this:

  • In a laptop that was running Windows 7 (x64) when they launched Profiler.exe (the one installed with SQL Server 2008), attempted to create a new trace connecting to an instance of SQL Server 2005 (9.00.4035 which corresponded to SP3), the “Events Selection” tab showed (obviously, only after having enabled the “Show all columns”) the EventSubclass column as one selectable for the Audit Login & Audit Logout event classes. Just like shown in the following screen captures, and exactly what one would expect:

image

image

  • Just within the same instance of SQL Server Profiler, when they tried to create a new trace definition against any instance of SQL Server (even against the same instance used to create the first definition as in the previous step), it didn’t show the EventSubclass column for the Audit Login and Audit Logout event classes.

image

  • In one of their servers that was running Windows Server 2003 Enterprise, where they had the same build of SQL Server Profiler installed as in the laptop mentioned before, this behavior wasn’t reproducible. From that server, every time they tried to define a new trace against any SQL Server instance running Service Pack 2 or above, they were able to see the EventSubclass column and it was clickable for the two event classes already mentioned.
  • We moved back to the laptop running Windows 7 x64 and repeated the same test but this time using the SQL Server Profiler 2005 (Profiler90.exe) which they had installed side-by-side with the one from 2008. Surprisingly, it worked as one would expect: always showed the EventSubclass column for the Audit Login and Audit Logout event classes while defining a new trace against any instance of SQL Server 2005 SP2 or higher build or version. Weird, isn’t it?

Well, at this point, it was clear that if I wanted to provide some credible explanation to what we were experiencing I better visited the code of the two versions of Profiler to try to understand why they both worked the way they did.

Surprisingly, the code that implements the load of a trace definition (i.e. that which is run when you create a new trace and connect to an instance of SQL Server) has NOT changed between 2005 and 2008 or 2008 R2. It basically does the following:

  • Connects to the instance of SQL Server specified and retrieves which events that instance of SQL produces, which columns are populated for each of those events, and whether the columns are filterable and/or repeatable (over a base column). In order to discover this information you will notice (if you trace it through another trace) that Profiler runs these two queries:

select

category_id, /*1*/

category_name, /*2*/

type, /*3*/

j.trace_event_id,/*4*/

name, /*5*/

j.trace_column_id, /*6*/

subclass_value, /*7*/

subclass_name from /*8*/

( select

a.category_id,

a.name as category_name,

a.type,

b.trace_event_id,

b.name,

trace_column_id

from

sys.trace_categories as a,

sys.trace_events as b,

sys.trace_event_bindings as c

where

(a.category_id=b.category_id) and (b.trace_event_id=c.trace_event_id)

) as j

left outer join

sys.trace_subclass_values as k

on (j.trace_column_id = k.trace_column_id)and(j.trace_event_id = k.trace_event_id ) order by category_name, name, j.trace_column_id, subclass_value, subclass_name

select

trace_column_id,

name,

type_name,

is_filterable,

is_repeatable,

is_repeated_base

from

sys.trace_columns order by trace_column_id

 

  • The result from the previous two queries is used for the first trace definition you attempt on any Profiler.exe process instance, and it is also saved to disk (or an attempt is made to save it to disk I should say to be more accurate. I’ll explain the details later on). The idea is to avoid querying the instance for the collection of events/columns it supports every time you define a new trace, so by saving the information retrieved on the first time to a local file, it can be used in the future whenever the local (cached) file exists. This local copy will be saved under %ProgramFiles%\Microsoft SQL Server\100\Tools\Profiler\TraceDefinitions (%ProgramFiles(x86)%\Microsoft SQL Server\100\Tools\Profiler\TraceDefinitions if the OS is a 64-bit SKU) under the name “Microsoft SQL Server TraceDefinition <MajorVersion> . <MinorVersion> . <BuildNumber> .xml”
  • On any subsequent attempt (within the same instance of Profiler) to create a new trace definition against any instance of SQL Server which runs the same major version, minor version, and build number, it will feed the events/columns information from that local file.
  • On any subsequent attempt (within the same instance of Profiler) to create a new trace definition against any instance of SQL Server which runs a given build (major version, minor version, and build number) for which there is no local matching file in the location mentioned above, it will go ahead and discover that information by running the two queries above and will cache it locally as explained before.
  • All this process works as long as Profiler doesn’t encounter any problem while trying to save the local file. Because, in the event it does, it sets a global variable indicating that a problem was encountered while trying to save one file to this location. As soon as this global variable indicates such problematic status, if you try to create a new trace definition for an instance of SQL Server for whose build there is no local file, it WON’T run the previous two queries as explained before, but it will failback instead to using the lowest common set of events available in any build of the major version targeted by the trace definition process. This lowest common set is deployed with the tools and is persisted on disk in %ProgramFiles%\Microsoft SQL Server\100\Tools\Profiler\TraceDefinitions (%ProgramFiles(x86)%\Microsoft SQL Server\100\Tools\Profiler\TraceDefinitions if the OS is a 64-bit SKU) under the name “Microsoft SQL Server TraceDefinition <MajorVersion> .0.0.xml”.

Having explained this, we can understand that the reason why it works the first time is because it bases the trace definition on what it retrieves from the two queries but, since the attempt to save the data to the local cache fails, any further attempt to define a new trace is based on the least common set mentioned before, which for SQL Server 2005 (Microsoft SQL Server TraceDefinition 9.0.0.xml) doesn’t include the EventSubclass columns for Audit Login and Audito Logout simply because it was only included as part of Service Pack 2 where the Common Compliance improvements was reverse integrated into SQL Server 2005.

Only one thing is still missing an explanation: Why on Earth it works with the version of Profiler deployed with SQL Server 2005, if the code providing that functionality hasn’t changed between Profiler.exe and its predecessor, Profiler90.exe?

The answer is in a subtle difference you can find out in the manifest embedded in the executable itself. The following chunk is part of the manifest embedded in PROFILER.EXE (2008 and R2) and is not part of the manifest embedded in PROFILER90.EXE:

<trustInfo xmlns="urn:schemas-microsoft-com:asm.v2">

  <security>

    <requestedPrivileges>

      <requestedExecutionLevel level="asInvoker" uiAccess="false">

      </requestedExecutionLevel>

    </requestedPrivileges>

  </security>

</trustInfo>

In the New UAC Technologies for Windows Vista document there is a section which covers Virtualization where they enumerate conditions under which virtualization is disabled. Those being: 1) 64 bit processes, 2) non-interactive processes, 3) processes that impersonate, 4) kernel mode callers, and 5) executables that have a requestedExecutionLevel. This system behavior is also covered in a table under Requested Execution Levels in the Step 6: Create and Embed an Application Manifest (UAC) topic.

So, what makes all this thing work with Profiler90.exe is that for Windows Vista, Windows 7, Windows 2008, and Windows 2008 R2 that executable meets all the requirements so that File Virtualization can be enabled for it. Therefore, any attempt made by Profiler90.exe to write to the system protected directory %ProgramFiles(x86)%\Microsoft SQL Server\90\Tools\Profiler\TraceDefinitions , is transparently redirected to %LocalAppData%\VirtualStore\Program Files (x86)\Microsoft SQL Server\90\Tools\Profiler\TraceDefinitions where the user has the right to create the new file and write any contents into it.

In the case of Profiler.exe, since its manifest includes the requestedExecutionLevel attribute, file virtualization is disabled for that executable and any attempt to create a file under %ProgramFiles(x86)%\Microsoft SQL Server\100\Tools\Profiler\TraceDefinitions is not redirected. Instead, it fails with an access denied, unless the process was created with elevated privileges.

In my opinion, this shouldn’t work in this way. The behavior is rather cumbersome and might seem even erratic to an end user. Therefore, I’ll go ahead and file a request to change this design for future releases of the product.