Tuesday, January 6, 2015

SQLServer:Wait Statistics(Waits started per second)\Log buffer waits - bogus values?

There are 128 in-memory transaction log buffers for each SQL Server database.  If none of them are free (a situation that is only typically encountered with high write latency and high concurrency of writes to the transaction log), threads in active transactions will accrue wait time for transaction log buffers.

In perfmon, this is accounted for with "SQLServer:Wait Statistics(*)\Log buffer waits".  To gauge if transaction log write performance is a bottleneck for high data rate ETL, I typically use  "Waits started per second".  Sometimes I use "Waits started per second" in conjunction with "(Average wait time (ms)". 

Some values are obviously bogus - various flavors of 1.84E+19 such as 18446744073709500000 are among my favorites

But today among the useful values in the range from 0 to 301 on a 6 vcpu system,  I see an abundance of these values, too.
38894
40103
40108
40111
40404
40711
40714
40736
40737
40738
40739

Anyone else seeing bogus values in the SQL Server wait-related perfmon numbers?  Is there something clever to eliminate these bogus values - maybe ensuring that 64 bit perfmon is launched, or some other trick?

******
5761 values collected, in 15 second increments.  This was the distribution.  I'll look through several more days worth of data.  the 1.84E+19 value is pretty easy to discard - even moreso if it always reports 0 as an average wait time.  All of the bogus values 38894 to 40739 report 49 ms as the average wait time.  Hmmm... so I may be able to discard values in a range with a particular reported wait time.


Average Wait Time Waits Started in 15 Seconds Occurrences
0 0 3488
0 1 1
0 1.84467E+19 722
14 4 1
19 24 1
21 60 1
22 3 1
24 13 1
24 301 1
25 8 1
28 14 1
29 3 1
29 4 1
32 152 1
34 3 1
34 12 1
34 25 1
35 6 1
37 4 1
38 4 1
45 7 1
46 8 1
49 38894 718
49 40103 11
49 40108 2
49 40111 3
49 40404 1
49 40711 2
49 40714 103
49 40736 18
49 40737 126
49 40738 7
49 40739 525
53 5 1
55 3 1
56 47 1
58 4 1
62 14 1
63 2 1
67 9 1
71 1 1
106 85 1
115 17 1
119 1 1
134 1 1
166 4 1
177 2 1
184 4 1


When I asked #sqlhelp about this, Paul Randal indicated (rightly so) that there are more reliable methods of gathering this information - such as extended events and the SQL Server wait DMV.  I use the wait DMV pretty extensively, too - usually in 5 minute increments.  But I also have a need for something very lightweight, minimally invasive (particularly requiring low privileges), and easily deployable across numerous systems - so I'll still pursue this a bit.

No comments:

Post a Comment