How to use LogParser, SQL Server and ETW to find reasons for exceptions.
Today I’ll show you how to make life easier using ETW (or BID) tracing, Log Parser and a SQL Server.
This will be a simplified example, but it should be enough to get you going and further troubleshoot your issues.
So, the first thing we need is something that crashes.
Here you will have full control of the application etc. But in the real world this is probably a deployed application and you may not
have all your regular tools for trouble shooting.
Start with creating a new C# console application with the following code.
static void Main(string[] args)
{
Console.WriteLine("Press any key to start.");
Console.Read();
string cs = @"Data Source=<your server>;Initial Catalog=Northwind;Integrated Security=TRUE";
using (SqlConnection con = new SqlConnection(cs))
{
for (int i = 0; i < 10; i++)
{
con.Open();
SqlCommand cmd = con.CreateCommand();
cmd.CommandText = "SELECT CustomerId, CompanyName, City FROM Customers WHERE CustomerId = @id";
cmd.Parameters.Add("@id", System.Data.SqlDbType.NChar, 5).Value = "ALFKI";
if (i == 5)
{
cmd.CommandText = cmd.CommandText.Replace("CompanyName", "CompanyNam");
}
SqlDataReader rdr = cmd.ExecuteReader();
while (rdr.Read())
{
Console.WriteLine("Iteration: {0}", i.ToString());
Console.WriteLine("\t{0} {1} {2}", rdr[0], rdr[1], rdr[2]);
}
rdr.Close();
con.Close();
Console.WriteLine("Waiting... (For dramatic effect only!)");
Thread.Sleep(1000);
}
}
}
So this will connect to the trusted Northwind. It will select some customer data based on the provided ID.
When it has done this 5 times we’ll change one of the column names in the query. This will generate a SqlException (“Invalid column name ‘CompanyNam’”).
But when you have deployed this, then when running you would get the following:
So it is not obvious what is going on. The first step would now be to take the .etl file for the crashing application.
This is done like by first adding the diagnostics AdoNetDiag.dll in the registry. The dlls are found here:
For .Net 2.0, default location is:
C:\Windows\Microsoft.NET\Framework\v2.0.50727\AdoNetDiag.dll
For .Net 4.0, default location is:
C:\Windows\Microsoft.NET\Framework\v4.0.30319\AdoNetDiag.dll
Start regedit (Start->Run->regedit) and navigate to:
HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\BidInterface\Loader
Create a new String Value key (REG_SZ) here. Set the name to :Path (with the colon), then set the value to be the full path to the AdoNetDiag.dll
Example of exported registry key (we are using .Net 2.0 here):
Key Name: HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\BidInterface\Loader
Name: :Path
Type: REG_SZ
Data: C:\Windows\Microsoft.NET\Framework\v2.0.50727\AdoNetDiag.dll
Then create a directory called C:\ETWDemo
Navigate to it in a command prompt that is running as administrator.
Run the following command:
C:\ETWDemo>logman start ETWDemoTrace -p {914ABDE2-171E-C600-3348-C514171DE148} 0x00000000 -ct perf -o ETWDemoTrace.etl –ets
(Here ETWTrace is an name of choice, the GUID is the System.Data provider, -ct specifies what clock resolution to use, -o is the path for output file, -ets is to
how to send the commands. Run logman /? for a full list of commands).
Run the application until it fails. Then stop the trace with the following command:
C:\ETWDemo>logman stop ETWDemoTrace -ets
You should now have the a file called ETWDemo.etl in C:\ETWDemo
Time to parse this and push it into a SQL Server table. If you do not have Log Parser installed, then download it from here:
”Log Parser 2.2”
Then use the same command window that you used earlier and navigate to where you have Log Parser installed, should be (depending on 32 or 64 bit machine).
C:\Program Files (x86)\Log Parser 2.2\LogParser
or
C:\Program Files\Log Parser 2.2\LogParser
Then run the following command:
LogParser "SELECT * INTO ETWDemoTable FROM C:\ETWDemo\ETWDemoTrace.etl" -FMode:Full -i:ETW -o:SQL -server:<your sql server> -database:<your database> -driver:"SQL Server" -createTable:ON
Here the SELECT specifies what to grab from the file.
We specify the file location.
-Fmode instructs to use full set of fields.
-i specifies input type, which is etw in this case.
-o specifies output type, which is SQL Server in this case.
-server and –database is the server and database where the table will be stored. In this case it is ETWDemoTable and it will be created since we have –createTable set to ON.
See full help in the logparser installation directory.
This should give an output like so:
Statistics:
-----------
Elements processed: 123
Elements output: 123
Execution time: 2.17 seconds
Now you have a table in SQL Server containing the parsed output.
So open SSMS and start querying for what you may be interested in. For example, checking for entries containing warnings or errors would be useful.
Running this would give just that:
select * from ETWDemoTable
where msgStr like '%error%'
or msgStr like '%warning%'
and in this case, the output would give the following (columns except “msgStr” removed):
<sc.SqlError.SqlError|ERR> infoNumber=207, errorState=1, errorClass=16, errorMessage='Invalid column name 'CompanyNam'.', procedure='', lineNumber=1
This is a very ‘small’ application so not many rows are going into the SQL Server from the .etl file.
But if you have been tracing for a while and a lot of things happened then it potentially may have millions of rows in it and the power of querying from SSMS is most welcome.
Comments
Anonymous
October 22, 2011
The same thing can be done with prfiler in less steps, then why to use ETW?Anonymous
June 08, 2012
Very good work. Thanks for sharing! @ManishKumar1980 Yes, this sample would also be traceable with Profiler. However, ETW can move the overhead from DB server to the app-server and ETW can handle much more than only SQL Server related tracing, plus some nice features like rolling files. @Michael: You need a "Share on G+" option. :o) Cheers Flo