What I learned today – temp file created when reading from multiple trace files

I’m going to do some updating on past posts before moving forward on my BI learning. Today I want to close the book on using Profiler.

First, there’s an excellent series of three webcasts on Profiler on the MSDEV website. MSDEV is a great resource for anyone looking for webcasts on Microsoft developer products. Check out the site even if you’re familiar with Profiler, chances are you’ll find something you didn’t know before in one of the other webcast series.

Second, Profiler will create a temporary file when you read from multiple trace files. Like a lot of things, I found this out by accident. I had created a trace for replay on one of our production servers. It wasn’t until the trace had been running for a while that I noticed that I had forgotten to change the maximum size of the trace files. I let the trace complete, knowing I could read them all later. My trace ended up creating 369 .trc files totaling about 1.89 GB.

So I began reading all of the .trc files, meaning to save the results into one .trc file. While the trace was running, I noticed that the amount of free space on the C drive of my test server was dropping. It eventually bottomed out when the trace finished reading the files. And when I investigated, I found a file in my Local Settings\Temp folder that was the same size as the total size of the 369 .trc files. The temp file was deleted automatically when I closed the Profiler session. Finally I opened the single large .trc file I saved when reading the multiple smaller .trc files. This time no temporary files at all were created.

I wasn’t expecting the temp file to be created. Luckily this happened on my test server where i had enough free space. But it’s something to consider anyway. You may easily run out of space on your C drive without knowing why. I don’t know what would happen if I read the same trace with fewer, larger .trc files, that’s something I’ll need to look at for sure.

Updates to previous posts

In my posts on virtualization I forgot to mention something. While I did say I was running with the multi-thread option instead of the replay in order option, I left the number of threads at the default of 4. I ran it with 64 threads earlier, but with the replay in order option. Those replays took well over 5 hours, as opposed to 2 1/2 – 3 hours with multi-thread at 4. But if I compare multi-threading at 4 with multi-threading at 64, then the times are much better – 3 1/2 hours compared to 2 3/4 hours on the same virtual server. I’ll summarize all my tests in a few weeks when I’ve completed all my tests.

The second post I need to update regards repeating data in a page header using SSRS. I solution was to use a shared variable. This had potential problems which I neglected to mention. If you use a shared variable then anyone running the report at the same time could overwrite each other values. I knew this at the time I put the report into production, but I thought the odds of that happening would be slim. Later I found I could produce that exact behavior in testing; when I ran the report simultaneously with another tester we did indeed cross values.

I changed the report to use a hashtable instead. The value in each record would be unique since it will depend on the user id of whoever is running the report. As an example of repeating a customer name on each page I

1. Added a hidden row to the top of the table control on the report. The table was already there and the grouping was already set on the customer name.
2. Added the customer name field from the table’s dataset to the hidden row.
3. In the report code section I added a shared hashtable – DIM htCustomer AS system.collections.hashtable = NEW system.collections.hashtable. The hashtable still needs to be shared.
4. Still in the code section, I added a new function to add a record to the hastable if it didn’t exist or update it if it did. The function takes three parameters; the value from the hidden field, a group name, and the user id. It returns the customer name for the current user

DIM key AS STRING = groupName & UserID
IF NOT group IS NOTHING
   DIM g  AS STRING= CTYPE(group, STRING)
      IF NOT (htCustomer.ContainsKey(key) THEN
          htCustomer.Add(key, g)
      ELSE
          IF NOT (htCustomer(key).Equals(g)) THEN
              htCustomer(key) = g)
          END IF 
      END IF
END IF
RETURN htCustomer(key)

5. Add a page header to the report. Add a new text box that uses an expression to call the function and pass in the parameters

=Code.SetCustomerName(ReportItems!txtCustomer.Value, “Customer”, User!UserID)

ReportItems!txtCustomer is the hidden field; Customer is my group name, and User!ID is a global parameter available to the report.  

Replaying Traces – What I’ve Learned

So I’ve been running these replays for a while now, with mixed results. There are a number of  lessons I’ve learned along the way.

• Check what’s running inside the workload you’re replaying. There may be something that will affect the replay. In my case there was a collection trace that was started by the third party software I use for monitoring the production servers for performance. Since this trace had no corresponding stop, it kept running after the rest of my workload was completed, making me think there was a different issue. The only thing I don’t understand is why it stopped on it’s own in half the replays.
• After you load the workload, you can apply a filter and reload the workload. This is how I eliminated any call for sp_trace_setstatus.
• Restore the master database to eliminate any replay errors due to mismatched database id’s. This comes directly from BOL. I was ignoring it because at first I wasn’t seeing any errors. But later, especially after I started on the virtual servers, I was seeing more and more errors where SQL wasn’t running against the right database. So when I started the last round of replays I restored the master db first.

I’m in the process of replaying all scenarios again so the data is consistent. So far I’ve completed the 4 physical tests. Coming next are the 3 32-bit virtual, 2 64-bit virtual, and 1 final with VMWare’s 8 CPU server.

Replaying traces, Part 5

So I’m now testing my workload on a virtual 64 bit server, again hosted by VMWare, again with only 4 CPUs. And again I find more issues.

I ran this replay 3 times so far. All three times the replay appeared to have hung at the 99% mark, similar to the 8 CPU physical test. The only difference was that, for the final test, I didn’t save the results to disk. I did this because on the second test there appeared to be SQL activity that was suspended by the TRACEWRITE wait type. The drive it was writing to was the only virtual drive; all databases are on SAN storage.

While all three hung at the 99% mark after about 3 hours, each test had different results. The first test was showing transactions against the database throughout the trace (the black line. The blue line is % Processor Time, the yellow line is % Privilege Time, the red line is transactions/sec against tempdb). The Processor time showed activity from the Profiler after the 99% mark .
The second trace showed no transactions after the 99% mark. This is the one that showed the TRACEWRITE wait type. Notice that there are no transactions against the db after the 3 hour mark this time.  
Test 3 shows the same pattern as test 1. There were no wait times for tests 1 and 3.

There is one more issue with these three tests. After stopping the replays, I had to manually kill the Profiler process because profiler became unresponsive. The third test stayed alive and was stopping the process and I let it go. However the next morning I checked and it was still “stopping” after 13 hours. And the Profiler was still responding.

The more I run these replays the more confused I get. I’m going to try one more time. This run will be from a remote machine, I’m only going to capture the counters on the virtual server.

Replaying traces, Part 3

I had a few surprises when I began replaying a production workload on a virtual server. I'm using the same workload I captured from a production server and replayed on a physical server in different scenarios. The first virtual test was on a 32 bit server hosted on a VMWare box with CPU affinity turned on. A limitation of virtual servers (at least for now) is that they are limited to 4 CPUs.

The first surprise was that the replay was faster than the 4 CPU test on a physical server, 3:07 virtual compared to 3:40 physical. The second surprise is that the total number of transactions appeared to have dropped.

I'll be looking into this to see what I'm missing, and I'll post more details soon.

Replaying traces, Part 2

When I left off, I was discussing using SQL Profiler to replay a trace taken on a production server on different test boxes with different configurations. The end result is to see if we can virtualize our production OLTP database servers.

Our next step in testing was to test replaying a trace on the same server it was captured on. We couldn’t do this on a production server so we used our testing server and assigned our developers to hit the database with our application for one hour. Afterwards we restored the databases to the same state they were in and replayed the trace using the same options we use on the other server tests; using multi-threading, not displaying results, and not replaying server SPIDs. The replay of the trace took only 45 minutes. We probably didn’t capture a large enough workload. But we did rule out the overhead of running the replay when comparing to performance of the production server when the workload was captured.

Back to testing. Since we can’t exactly duplicate the replay of the workload to match the production server, we decided that running the replay on the test server would be our new baseline since we could duplicate that for every test. Testing on the physical box showed the following:

	Production	16 CPU (new baseline)	4 CPU, HT ON	4 CPU, HT OFF
Time	1:07	2:37	3:40	2:44
Avg CPU	17%	24%	83%	77%

We expected the 4 CPU tests to take longer and use more CPU. We were surprised that the 4 CPU test with hyper-threading turned off performed better than with hyper-threading on. So we ran one more test, using all physical processors and turning ht off. This gave us 8 physical processors to work with. This test, though, was incomplete. We ran it twice and both time the replay appeared to hang after completing 99%. Both times we needed to kill the replay after 5 hours. The counters we captured weren’t valid.

I’ll post on testing on a virtual server in a future post.

Technorati Tags: SQL,Trace replay

Replaying traces with SQL Profiler

One of the projects I've become involved with at work has been the virtualization of our regional databases. However, when we hooked up a copy of one of the databases in a virtual environment we noticed a huge performance degradation, mainly in regard to CPU usage. The only part of the server that was virtualized was the drive containing the OS. User databases were mainly placed on a SAN so the IO looked to be acceptable, at least based on the small workload we generated. We know that the servers were not comparable; the current, physical server has 16 CPUs, where the virtual server is limited by VMWare to 4. Since performance was much worse than expected, we decided to try and replay a workload from one of our production servers on a virtual server and compare the results.
 
We thought of a few different ways to do this, but we eventually decided on using the replay ability of SQL Profiler. So we captured a trace from production, set up a copy of the databases on a second physical server configured identically to the production server, then used the different options inside profiler for the replay. What we saw was surprising.

The original trace was run for an hour. Using the multithreading option on the test box, the replay took twice as long, and the CPU usage was at least 10% higher for the length of the replay. When we set the number of threads to 64, the replay took 5 hours, and the CPU usage was maybe 25% of the original trace.

So the next step is to replay a trace on the same server to see what the results are. I'll post more on this in a few days, after a few more test cases. I'll also include some of the actual numbers.