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”

https://www.microsoft.com/downloads/en/details.aspx?FamilyID=890cd06b-abf8-4c25-91b2-f8d975cf8c07&displaylang=en

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.