DBCC sqlperf(waitstats) OLEDB Problem
-
I'm looking at the waitstats on a dual-cpu SQL2K SP4 W2003 SP1 server. I was logging the values every 10 minutes to attempt to understand how bad our CXPACKET wait problem is. We have hyper threading enabled.
I noted strange values for the [Signal Wait Time] for the OLEDB [Wait Type]. The [Signal Wait Time] is larger than the [Wait Time]. I see this on more than one server. I thought the [Wait Time] included the [Signal Wait Time] and would always be larger. In addition, the [Signal Wait Time] is rather large and can jump in value quickly. I cleared the counters a few hours ago.
Anybody have any idea what's happening? Is this normal? A bug? We do have a linked servers to other SQL Servers. Are specific RPC settings required? DTC? I'm perplexed.
dbcc sqlperf(waitstats):
Wait Type Requests Wait Time Signal Wait Time
-------------------------------- ------------------------ ------------------------ ------------------------
MISCELLANEOUS 18.0 0.0 0.0
LCK_M_SCH_S 0.0 0.0 0.0
LCK_M_SCH_M 0.0 0.0 0.0
LCK_M_S 0.0 0.0 0.0
LCK_M_U 0.0 0.0 0.0
LCK_M_X 0.0 0.0 0.0
LCK_M_IS 1.0 1375.0 0.0
LCK_M_IU 0.0 0.0 0.0
LCK_M_IX 0.0 0.0 0.0
LCK_M_SIU 0.0 0.0 0.0
LCK_M_SIX 0.0 0.0 0.0
LCK_M_UIX 0.0 0.0 0.0
LCK_M_BU 0.0 0.0 0.0
LCK_M_RS_S 0.0 0.0 0.0
LCK_M_RS_U 0.0 0.0 0.0
LCK_M_RIn_NL 0.0 0.0 0.0
LCK_M_RIn_S 0.0 0.0 0.0
LCK_M_RIn_U 0.0 0.0 0.0
LCK_M_RIn_X 0.0 0.0 0.0
LCK_M_RX_S 0.0 0.0 0.0
LCK_M_RX_U 0.0 0.0 0.0
LCK_M_RX_X 0.0 0.0 0.0
SLEEP 14415.0 1.3117547E+7 1.3117471E+7
IO_COMPLETION 200.0 214.0 0.0
ASYNC_IO_COMPLETION 0.0 0.0 0.0
RESOURCE_SEMAPHORE 0.0 0.0 0.0
DTC 0.0 0.0 0.0
OLEDB 754.0 17291.0 3.2390843E+9
FAILPOINT 0.0 0.0 0.0
RESOURCE_QUEUE 22958.0 3.9133252E+7 1.3120686E+7
ASYNC_DISKPOOL_LOCK 0.0 0.0 0.0
UMS_THREAD 0.0 0.0 0.0
PIPELINE_INDEX_STAT 0.0 0.0 0.0
PIPELINE_LOG 0.0 0.0 0.0
PIPELINE_VLM 0.0 0.0 0.0
WRITELOG 6925.0 3498.0 140.0
LOGBUFFER 1045.0 1609.0 0.0
PSS_CHILD 0.0 0.0 0.0
EXCHANGE 12.0 0.0 0.0
XCB 0.0 0.0 0.0
DBTABLE 0.0 0.0 0.0
EC 0.0 0.0 0.0
TEMPOBJ 0.0 0.0 0.0
XACTLOCKINFO 0.0 0.0 0.0
LOGMGR 0.0 0.0 0.0
CMEMTHREAD 134.0 0.0 0.0
CXPACKET 5390.0 201792.0 357.0
PAGESUPP 326.0 0.0 0.0
SHUTDOWN 0.0 0.0 0.0
WAITFOR 335.0 3350747.0 3350747.0
CURSOR 0.0 0.0 0.0
EXECSYNC 0.0 0.0 0.0
LATCH_NL 0.0 0.0 0.0
LATCH_KP 0.0 0.0 0.0
LATCH_SH 0.0 0.0 0.0
LATCH_UP 1.0 0.0 0.0
LATCH_EX 397855.0 153225.0 12028.0
LATCH_DT 0.0 0.0 0.0
PAGELATCH_NL 0.0 0.0 0.0
PAGELATCH_KP 0.0 0.0 0.0
PAGELATCH_SH 2059.0 47.0 47.0
PAGELATCH_UP 2460.0 110.0 32.0
PAGELATCH_EX 2959.0 16.0 16.0
PAGELATCH_DT 0.0 0.0 0.0
PAGEIOLATCH_NL 0.0 0.0 0.0
PAGEIOLATCH_KP 0.0 0.0 0.0
PAGEIOLATCH_SH 17575.0 185186.0 268.0
PAGEIOLATCH_UP 84.0 31.0 0.0
PAGEIOLATCH_EX 469.0 3595.0 0.0
PAGEIOLATCH_DT 0.0 0.0 0.0
TRAN_MARK_NL 0.0 0.0 0.0
TRAN_MARK_KP 0.0 0.0 0.0
TRAN_MARK_SH 0.0 0.0 0.0
TRAN_MARK_UP 0.0 0.0 0.0
TRAN_MARK_EX 0.0 0.0 0.0
TRAN_MARK_DT 0.0 0.0 0.0
NETWORKIO 18413.0 847711.0 0.0
Total 494388.0 5.7017244E+7 3.2686861E+9
(78 row(s) affected)
DBCC execution completed. If DBCC printed error messages, contact your system administrator.
Randy
RandyHelpdesk: Perhaps Im not the only one that does not know what you are doing. 😉
-
Here are the results of logging since yesterday. I expect a SignalWaitTime rollover soon after about 4.3E9. The timing interval is 10 minutes. The jump from 29628864 to 3239083520 (37 days) is a long time to wait in just one 10 minute interval.
select CONVERT(varchar(19), MonitorTime, 120) as [MonitorTime],
LEFT(WaitType, 8) as [WaitType],
STR(WaitTime, 8) as [WaitTime],
STR(SignalWaitTime, 14) as [SignalWaitTime]
from dbo.waitstatslog
where WaitType = 'OLEDB'
order by MonitorTime desc, WaitType
MonitorTime WaitType WaitTime SignalWaitTime
------------------- -------- -------- --------------
2006-08-17 09:40:03 OLEDB 19679 3239133440
2006-08-17 09:30:03 OLEDB 19400 3239131136
2006-08-17 09:20:03 OLEDB 19400 3239131136
2006-08-17 09:10:03 OLEDB 19400 3239130624
2006-08-17 09:00:03 OLEDB 19305 3239129600
2006-08-17 08:50:03 OLEDB 19054 3239127552
2006-08-17 08:40:03 OLEDB 18665 3239123712
2006-08-17 08:30:03 OLEDB 18431 3239121920
2006-08-17 08:20:03 OLEDB 18073 3239119104
2006-08-17 08:10:03 OLEDB 18073 3239118336
2006-08-17 08:00:03 OLEDB 17556 3239114496
2006-08-17 07:50:03 OLEDB 17447 3239113472
2006-08-17 07:40:03 OLEDB 17447 3239112704
2006-08-17 07:30:03 OLEDB 17447 3239112704
2006-08-17 07:20:03 OLEDB 17447 3239112704
2006-08-17 07:10:03 OLEDB 17291 3239110400
2006-08-17 07:00:03 OLEDB 17291 3239110400
2006-08-17 06:50:03 OLEDB 17291 3239110400
2006-08-17 06:40:03 OLEDB 17291 3239109632
2006-08-17 06:30:03 OLEDB 17291 3239109632
2006-08-17 06:20:03 OLEDB 17291 3239109632
2006-08-17 06:10:03 OLEDB 17291 3239108864
2006-08-17 06:00:03 OLEDB 17291 3239108864
2006-08-17 05:50:03 OLEDB 17291 3239108864
2006-08-17 05:40:03 OLEDB 17291 3239108096
2006-08-17 05:30:03 OLEDB 17291 3239108096
2006-08-17 05:20:03 OLEDB 17291 3239108096
2006-08-17 05:10:03 OLEDB 17291 3239107328
2006-08-17 05:00:04 OLEDB 17291 3239107328
2006-08-17 04:50:03 OLEDB 17291 3239107328
2006-08-17 04:40:03 OLEDB 17291 3239106560
2006-08-17 04:30:03 OLEDB 17291 3239106560
2006-08-17 04:20:03 OLEDB 17291 3239106560
2006-08-17 04:10:03 OLEDB 17291 3239105792
2006-08-17 04:00:04 OLEDB 17291 3239105792
2006-08-17 03:50:03 OLEDB 17291 3239105792
2006-08-17 03:40:03 OLEDB 17291 3239105024
2006-08-17 03:30:03 OLEDB 17291 3239105024
2006-08-17 03:20:03 OLEDB 17291 3239105024
2006-08-17 03:10:03 OLEDB 17291 3239103744
2006-08-17 03:00:03 OLEDB 17291 3239103744
2006-08-17 02:50:03 OLEDB 17291 3239103744
2006-08-17 02:40:03 OLEDB 17291 3239102208
2006-08-17 02:30:03 OLEDB 17291 3239102208
2006-08-17 02:20:03 OLEDB 17291 3239102208
2006-08-17 02:10:03 OLEDB 17291 3239101440
2006-08-17 02:00:03 OLEDB 17291 3239101440
2006-08-17 01:50:03 OLEDB 17291 3239101440
2006-08-17 01:40:03 OLEDB 17291 3239100672
2006-08-17 01:30:03 OLEDB 17291 3239100672
2006-08-17 01:20:03 OLEDB 17291 3239100672
2006-08-17 01:10:03 OLEDB 17291 3239099904
2006-08-17 01:00:03 OLEDB 17291 3239099904
2006-08-17 00:50:03 OLEDB 17291 3239099904
2006-08-17 00:40:03 OLEDB 17291 3239099136
2006-08-17 00:30:03 OLEDB 17291 3239099136
2006-08-17 00:20:03 OLEDB 17291 3239099136
2006-08-17 00:10:03 OLEDB 17291 3239098368
2006-08-17 00:00:04 OLEDB 17291 3239098368
2006-08-16 23:50:03 OLEDB 17291 3239096320
2006-08-16 23:40:03 OLEDB 17291 3239095552
2006-08-16 23:30:03 OLEDB 17291 3239095552
2006-08-16 23:20:03 OLEDB 17291 3239095552
2006-08-16 23:10:03 OLEDB 17291 3239094016
2006-08-16 23:00:03 OLEDB 17291 3239094016
2006-08-16 22:50:04 OLEDB 17291 3239094016
2006-08-16 22:40:03 OLEDB 17291 3239093248
2006-08-16 22:30:03 OLEDB 17291 3239093248
2006-08-16 22:20:03 OLEDB 17291 3239093248
2006-08-16 22:10:03 OLEDB 17291 3239092480
2006-08-16 22:00:03 OLEDB 17291 3239092480
2006-08-16 21:50:03 OLEDB 17291 3239092480
2006-08-16 21:40:03 OLEDB 17291 3239091712
2006-08-16 21:30:03 OLEDB 17291 3239091712
2006-08-16 21:20:03 OLEDB 17291 3239091712
2006-08-16 21:10:03 OLEDB 17291 3239090944
2006-08-16 21:00:03 OLEDB 17291 3239090944
2006-08-16 20:50:03 OLEDB 17291 3239090944
2006-08-16 20:40:03 OLEDB 17291 3239090176
2006-08-16 20:30:03 OLEDB 17291 3239090176
2006-08-16 20:20:03 OLEDB 17291 3239090176
2006-08-16 20:10:03 OLEDB 17291 3239089408
2006-08-16 20:00:03 OLEDB 17291 3239089408
2006-08-16 19:50:03 OLEDB 17291 3239089408
2006-08-16 19:40:03 OLEDB 17291 3239088640
2006-08-16 19:30:03 OLEDB 17291 3239088640
2006-08-16 19:20:03 OLEDB 17291 3239088640
2006-08-16 19:10:03 OLEDB 17291 3239087872
2006-08-16 19:00:03 OLEDB 17291 3239087872
2006-08-16 18:50:03 OLEDB 17291 3239087872
2006-08-16 18:40:03 OLEDB 17291 3239087360
2006-08-16 18:30:03 OLEDB 17291 3239087360
2006-08-16 18:20:03 OLEDB 17291 3239087360
2006-08-16 18:10:03 OLEDB 17291 3239086592
2006-08-16 18:00:03 OLEDB 17291 3239086592
2006-08-16 17:50:03 OLEDB 17291 3239086592
2006-08-16 17:40:03 OLEDB 17291 3239085824
2006-08-16 17:30:03 OLEDB 17291 3239085824
2006-08-16 17:20:03 OLEDB 17291 3239085824
2006-08-16 17:10:03 OLEDB 17291 3239085056
2006-08-16 17:00:03 OLEDB 17291 3239085056
2006-08-16 16:50:03 OLEDB 17291 3239085056
2006-08-16 16:40:03 OLEDB 17291 3239084288
2006-08-16 16:30:03 OLEDB 17291 3239084288
2006-08-16 16:20:03 OLEDB 17291 3239084288
2006-08-16 16:10:03 OLEDB 17291 3239083520
2006-08-16 16:00:03 OLEDB 17291 3239083520
2006-08-16 15:50:03 OLEDB 17291 3239083520
2006-08-16 15:40:03 OLEDB 16870 29628864
2006-08-16 15:30:03 OLEDB 16759 29627768
2006-08-16 15:20:03 OLEDB 2228 342398
2006-08-16 15:10:03 OLEDB 1699 93855
2006-08-16 15:00:03 OLEDB 654 10092
2006-08-16 14:50:03 OLEDB 654 10092
2006-08-16 14:40:03 OLEDB 654 9348
2006-08-16 14:30:03 OLEDB 654 9348
2006-08-16 14:20:03 OLEDB 654 9348
2006-08-16 14:10:03 OLEDB 654 7836
2006-08-16 14:00:03 OLEDB 592 7135
2006-08-16 13:50:03 OLEDB 405 5256
2006-08-16 13:40:03 OLEDB 234 2876
2006-08-16 13:30:03 OLEDB 109 1755
2006-08-16 13:20:03 OLEDB 0 744
2006-08-16 13:10:03 OLEDB 0 0
2006-08-16 13:00:03 OLEDB 0 0
2006-08-16 12:50:03 OLEDB 0 0
(126 row(s) affected)
Randy
RandyHelpdesk: Perhaps Im not the only one that does not know what you are doing. 😉
-
While I'm at it, here are the other wait types. I'm tempted to just ignore the OLEDB counter and remove it from "***Total***", but I am worried that something might be wrong. Perhaps I need to go back to the start and ask if my CXPACKET values indicate that hyper threading should be disabled.
WaitType Requests WaitTime SignalWaitTime
-------------------- -------- --------- --------------
MISCELLANEOUS 88 0 0
LCK_M_SCH_S 0 0 0
LCK_M_SCH_M 0 0 0
LCK_M_S 0 0 0
LCK_M_U 0 0 0
LCK_M_X 0 0 0
LCK_M_IS 1 1375 0
LCK_M_IU 0 0 0
LCK_M_IX 0 0 0
LCK_M_SIU 0 0 0
LCK_M_SIX 0 0 0
LCK_M_UIX 0 0 0
LCK_M_BU 0 0 0
LCK_M_RS_S 0 0 0
LCK_M_RS_U 0 0 0
LCK_M_RIn_NL 0 0 0
LCK_M_RIn_S 0 0 0
LCK_M_RIn_U 0 0 0
LCK_M_RIn_X 0 0 0
LCK_M_RX_S 0 0 0
LCK_M_RX_U 0 0 0
LCK_M_RX_X 0 0 0
SLEEP 78163 76799800 76799720
IO_COMPLETION 808 2083 0
ASYNC_IO_COMPLETION 72 356 0
RESOURCE_SEMAPHORE 0 0 0
DTC 0 0 0
OLEDB 2369 26186 3240771840
FAILPOINT 0 0 0
RESOURCE_QUEUE 101632 230271792 76803088
ASYNC_DISKPOOL_LOCK 1116 0 0
UMS_THREAD 0 0 0
PIPELINE_INDEX_STAT 0 0 0
PIPELINE_LOG 0 0 0
PIPELINE_VLM 0 0 0
WRITELOG 33270 25352 599
LOGBUFFER 1129 5642 0
PSS_CHILD 0 0 0
EXCHANGE 250 27963 0
XCB 0 0 0
DBTABLE 0 0 0
EC 0 0 0
TEMPOBJ 0 0 0
XACTLOCKINFO 0 0 0
LOGMGR 0 0 0
CMEMTHREAD 765 0 0
CXPACKET 64183 1687563 4039
PAGESUPP 1966 15 15
SHUTDOWN 0 0 0
WAITFOR 1222 12216503 12213440
CURSOR 0 0 0
EXECSYNC 0 0 0
LATCH_NL 0 0 0
LATCH_KP 0 0 0
LATCH_SH 0 0 0
LATCH_UP 18 0 0
LATCH_EX 2333414 581306 54057
LATCH_DT 0 0 0
PAGELATCH_NL 0 0 0
PAGELATCH_KP 0 0 0
PAGELATCH_SH 3578 95 63
PAGELATCH_UP 16545 344 251
PAGELATCH_EX 11364 109 78
PAGELATCH_DT 0 0 0
PAGEIOLATCH_NL 0 0 0
PAGEIOLATCH_KP 0 0 0
PAGEIOLATCH_SH 58260 558841 693
PAGEIOLATCH_UP 663 266 0
PAGEIOLATCH_EX 986 7437 15
PAGEIOLATCH_DT 0 0 0
TRAN_MARK_NL 0 0 0
TRAN_MARK_KP 0 0 0
TRAN_MARK_SH 0 0 0
TRAN_MARK_UP 0 0 0
TRAN_MARK_EX 0 0 0
TRAN_MARK_DT 0 0 0
NETWORKIO 110984 911208 0
Total 2822846 323124192 3406647808
***Total*** 2641829 3836141 3240831650
(79 row(s) affected)
Randy
RandyHelpdesk: Perhaps Im not the only one that does not know what you are doing. 😉
-
It does rollover. It appears that an unsigned 4 byte integer is used for each counter. I've looked at the values of all counters on several machines. None are over 4.29E9. This is starting to look like a bug. (Perhaps it has something to do with casting a UINT to an INT.)
MonitorTime WaitType Requests WaitTime SignalWaitTime
------------------- -------- -------- -------- --------------
2006-08-18 08:20:03 OLEDB 5043 46026 1800406400
2006-08-18 08:10:03 OLEDB 4951 45023 1864382464
2006-08-18 08:00:03 OLEDB 4848 43616 1861685248
2006-08-18 07:50:03 OLEDB 4837 43508 1861684224
2006-08-18 07:40:03 OLEDB 4813 43508 1861683456
2006-08-18 07:30:03 OLEDB 4673 41732 1861357056
2006-08-18 07:20:03 OLEDB 4462 38906 1948362240
2006-08-18 07:10:03 OLEDB 4326 37374 1946178176
2006-08-18 07:00:03 OLEDB 4153 35122 1945493120
2006-08-18 06:50:03 OLEDB 4004 33026 3242128128
2006-08-18 06:40:03 OLEDB 3890 31855 3242081024
2006-08-18 06:30:03 OLEDB 3846 31358 3242076928
2006-08-18 06:20:03 OLEDB 3846 31358 3242076928
2006-08-18 06:10:03 OLEDB 3822 31358 3242076160
2006-08-18 06:00:03 OLEDB 3822 31358 3242076160
2006-08-18 05:50:03 OLEDB 3822 31358 3242076160
2006-08-18 05:40:03 OLEDB 3798 31358 3242075392
2006-08-18 05:30:03 OLEDB 3798 31358 3242075392
2006-08-18 05:20:03 OLEDB 3798 31358 3242075392
2006-08-18 05:10:03 OLEDB 3774 31358 3242074624
2006-08-18 05:00:04 OLEDB 3774 31358 3242074624
2006-08-18 04:50:03 OLEDB 3774 31358 3242074624
2006-08-18 04:40:03 OLEDB 3750 31358 3242073856
2006-08-18 04:30:03 OLEDB 3750 31358 3242073856
2006-08-18 04:20:03 OLEDB 3750 31358 3242073856
2006-08-18 04:10:03 OLEDB 3726 31358 3242073088
2006-08-18 04:00:04 OLEDB 3726 31358 3242073088
2006-08-18 03:50:03 OLEDB 3726 31358 3242073088
2006-08-18 03:40:03 OLEDB 3702 31358 3242072320
2006-08-18 03:30:03 OLEDB 3702 31358 3242072320
2006-08-18 03:20:03 OLEDB 3702 31358 3242072320
2006-08-18 03:10:03 OLEDB 3678 31358 3242070784
2006-08-18 03:00:03 OLEDB 3677 31358 3242070784
2006-08-18 02:50:03 OLEDB 3677 31358 3242070784
2006-08-18 02:40:03 OLEDB 3653 31358 3242069760
2006-08-18 02:30:03 OLEDB 3653 31358 3242069760
2006-08-18 02:20:03 OLEDB 3653 31358 3242069760
2006-08-18 02:10:03 OLEDB 3629 31358 3242068736
2006-08-18 02:00:03 OLEDB 3629 31358 3242068736
2006-08-18 01:50:03 OLEDB 3629 31358 3242068736
2006-08-18 01:40:03 OLEDB 3605 31358 3242065664
2006-08-18 01:30:03 OLEDB 3605 31358 3242065664
2006-08-18 01:20:03 OLEDB 3605 31358 3242065664
2006-08-18 01:10:03 OLEDB 3581 31358 3242064896
2006-08-18 01:00:03 OLEDB 3581 31358 3242064896
2006-08-18 00:50:03 OLEDB 3581 31358 3242064896
2006-08-18 00:40:03 OLEDB 3557 31358 3242064128
2006-08-18 00:30:03 OLEDB 3557 31358 3242064128
2006-08-18 00:20:03 OLEDB 3557 31358 3242064128
2006-08-18 00:10:03 OLEDB 3533 31358 3242063360
2006-08-18 00:00:04 OLEDB 3533 31358 3242063360
2006-08-17 23:50:03 OLEDB 3490 31358 3242061312
2006-08-17 23:40:03 OLEDB 3466 31358 3242060544
2006-08-17 23:30:03 OLEDB 3466 31358 3242060544
2006-08-17 23:20:03 OLEDB 3466 31358 3242060544
2006-08-17 23:10:03 OLEDB 3442 31358 3242059520
2006-08-17 23:00:03 OLEDB 3442 31358 3242059520
2006-08-17 22:50:04 OLEDB 3442 31358 3242059520
2006-08-17 22:40:03 OLEDB 3418 31358 3242058752
2006-08-17 22:30:03 OLEDB 3418 31358 3242058752
2006-08-17 22:20:03 OLEDB 3418 31358 3242058752
2006-08-17 22:10:03 OLEDB 3394 31358 3242057984
2006-08-17 22:00:03 OLEDB 3394 31358 3242057984
2006-08-17 21:50:03 OLEDB 3394 31358 3242057984
2006-08-17 21:40:03 OLEDB 3370 31358 3242057216
2006-08-17 21:30:03 OLEDB 3370 31358 3242057216
2006-08-17 21:20:03 OLEDB 3370 31358 3242057216
2006-08-17 21:10:03 OLEDB 3346 31358 3242056448
2006-08-17 21:00:03 OLEDB 3346 31358 3242056448
2006-08-17 20:50:03 OLEDB 3346 31358 3242056448
2006-08-17 20:40:03 OLEDB 3322 31358 3242055680
2006-08-17 20:30:03 OLEDB 3322 31358 3242055680
2006-08-17 20:20:03 OLEDB 3322 31358 3242055680
2006-08-17 20:10:03 OLEDB 3298 31358 3242055168
2006-08-17 20:00:03 OLEDB 3298 31358 3242055168
2006-08-17 19:50:03 OLEDB 3298 31358 3242055168
2006-08-17 19:40:03 OLEDB 3274 31358 3242054400
2006-08-17 19:30:03 OLEDB 3274 31358 3242054400
2006-08-17 19:20:03 OLEDB 3274 31358 3242054400
2006-08-17 19:10:03 OLEDB 3250 31358 3242053632
2006-08-17 19:00:03 OLEDB 3250 31358 3242053632
2006-08-17 18:50:03 OLEDB 3250 31358 3242053632
2006-08-17 18:40:03 OLEDB 3226 31358 3242052864
2006-08-17 18:30:03 OLEDB 3226 31358 3242052864
2006-08-17 18:20:03 OLEDB 3226 31358 3242052864
2006-08-17 18:10:03 OLEDB 3202 31358 3242052096
2006-08-17 18:00:03 OLEDB 3202 31358 3242052096
2006-08-17 17:50:03 OLEDB 3202 31358 3242052096
2006-08-17 17:40:03 OLEDB 3178 31358 3242051328
2006-08-17 17:30:03 OLEDB 3178 31358 3242051328
2006-08-17 17:20:03 OLEDB 3178 31358 3242051328
2006-08-17 17:10:03 OLEDB 3154 31358 3242050560
2006-08-17 17:00:03 OLEDB 3154 31358 3242050560
2006-08-17 16:50:03 OLEDB 3154 31358 3242050560
2006-08-17 16:40:03 OLEDB 3130 31358 3242049792
2006-08-17 16:30:03 OLEDB 3130 31358 3242049792
2006-08-17 16:20:03 OLEDB 3130 31358 3242049792
2006-08-17 16:10:03 OLEDB 3106 31358 3242049024
2006-08-17 16:00:03 OLEDB 3106 31358 3242049024
2006-08-17 15:50:03 OLEDB 3106 31358 3242049024
2006-08-17 15:40:03 OLEDB 3082 31358 3242048256
2006-08-17 15:30:03 OLEDB 3082 31358 3242048256
2006-08-17 15:20:03 OLEDB 3082 31358 3242048256
2006-08-17 15:10:03 OLEDB 3058 31358 3242047488
2006-08-17 15:00:03 OLEDB 3058 31358 3242047488
2006-08-17 14:50:03 OLEDB 3058 31358 3242047488
2006-08-17 14:40:03 OLEDB 3034 31358 3242046976
2006-08-17 14:30:03 OLEDB 3034 31358 3242046976
2006-08-17 14:20:03 OLEDB 3034 31358 3242046976
2006-08-17 14:10:03 OLEDB 3010 31358 3242046208
2006-08-17 14:00:03 OLEDB 3010 31358 3242046208
2006-08-17 13:50:03 OLEDB 3010 31358 3242046208
2006-08-17 13:40:03 OLEDB 2986 31358 3242045440
2006-08-17 13:30:03 OLEDB 2986 31358 3242045440
2006-08-17 13:20:03 OLEDB 2986 31358 3242045440
2006-08-17 13:10:03 OLEDB 2962 31358 3242044672
2006-08-17 13:00:03 OLEDB 2962 31358 3242044672
2006-08-17 12:50:03 OLEDB 2962 31358 3242044672
2006-08-17 12:40:03 OLEDB 2938 31358 3242043904
2006-08-17 12:30:03 OLEDB 2938 31358 3242043904
2006-08-17 12:20:03 OLEDB 2938 31358 3242043904
2006-08-17 12:10:03 OLEDB 2914 31358 3242043136
2006-08-17 12:00:03 OLEDB 2914 31358 3242043136
2006-08-17 11:50:03 OLEDB 2914 31358 3242043136
2006-08-17 11:40:03 OLEDB 2890 31358 3242042368
2006-08-17 11:30:03 OLEDB 2890 31358 3242042368
2006-08-17 11:20:03 OLEDB 2890 31358 3242042368
2006-08-17 11:10:03 OLEDB 2703 29467 3241696512
2006-08-17 11:00:03 OLEDB 2703 29467 3241696512
2006-08-17 10:50:03 OLEDB 2694 29391 3241696000
2006-08-17 10:40:03 OLEDB 2617 28657 3241321472
2006-08-17 10:30:03 OLEDB 2472 26968 3241229568
2006-08-17 10:20:03 OLEDB 2420 26435 3240774912
2006-08-17 10:10:03 OLEDB 2369 26186 3240771840
2006-08-17 10:00:03 OLEDB 2259 24921 3240008448
2006-08-17 09:50:03 OLEDB 2053 22395 3239673856
2006-08-17 09:40:03 OLEDB 1835 19679 3239133440
2006-08-17 09:30:03 OLEDB 1815 19400 3239131136
RandyHelpdesk: Perhaps Im not the only one that does not know what you are doing. 😉
-
I found some related links. This one describes similar results for the OLEDB counter.
http://www.sql-server-performance.com/forum/topic.asp?TOPIC_ID=8429&whichpage=1
This one has a bit of explaination of OLEDB, but not why the values appear invalid.
http://www.mcse.ms/archive86-2005-2-1406890.html
From the above link:
OLEDB waittype is an overloaded waittype to begin with, it is set for:
* linked server calls
* bulk insert
* running SQL Trace
* running 6.x to 7.0 or 2000 conversion imports
* materializing virtual tables like select * from master.dbo.sysprocesses
and select * from master.dbo.syslockinfo
I have been using the virtual tables a lot lately. Funny.
I might be creating the "problem" by trying to capture information about the problem. I think I'm going to ignore the OLEDB signal wait values. If anybody understands what this is about, I'd appreciate an explanation.
Randy
RandyHelpdesk: Perhaps Im not the only one that does not know what you are doing. 😉
-
Yup - I understand waits - why are you posting , do you have a performance problem or do you think you have a problem after looking at wait stats?
All processes will have a last wait type, collecting the information doesn't mean there's anything up it just may indicate a bottleneck - remember there always has to be a slowest section.
[font="Comic Sans MS"]The GrumpyOldDBA[/font]
www.grumpyolddba.co.uk
http://sqlblogcasts.com/blogs/grumpyolddba/ -
Hi Colin. I was looking at the CXPACKETS originally. I noticed some very large values after re-indexing some dbs. I was trying to determine if hyper threading might be a problem and also looking at "CPU pressure". I reduced the max degree of parallism to 2. I still see CXPACKET waits, but not as many. I've seen recommendations to limit parallism to #cpus - 1. I have a dual cpu with HT enabled. Does that mean 1 or 3? I was hoping to find a rule of thumb re HT to apply to all our servers. What do you think?
I got side tracked with OLEDB values. I though I had a problem. I just found another link that claims this is a bug. If so, it's been ignored a long time. If I remove the OLEDB value from the "***total***" sums, then the total will make more since when calculating CPU pressure. It appears CPU pressure is not an issue.
http://www.sqlmonster.com/Uwe/Forum.aspx/sql-server/6788/dbcc-sqlperf-waitstats-anomoly
RandyHelpdesk: Perhaps Im not the only one that does not know what you are doing. 😉
-
There seem to be constant postings about disabling HT which I think has almost reached urban myth status. I've used 2, 4 and 8 way boxes with HT and not had any problems. I've had cxpacket waits but in the main coded them out. I have some nice code which collects summary wait stats - comes from microsoft adapted by myself to be more useful ( sadly far too vast to attempt to post )
As you've noticed the waits decrease, well they would halve if you disabled HT thus proving that the HT wasn't the problem first time around. Set the parallelism to the number of physical cpu's, in your case it should be 2. I'd recommend you make sure you have a performance problem before making changes - I always try to leave everything as "out of the box" values unless I have exhausted every other means - so far I've not made many changes in 14 years!!!
Ultimately if it ain't broke don't fix it!! I'm not awrae of any bug concerning oledb waits.
[font="Comic Sans MS"]The GrumpyOldDBA[/font]
www.grumpyolddba.co.uk
http://sqlblogcasts.com/blogs/grumpyolddba/ -
I've created a job that logs the stats every 10 minutes and a report that lists the delta for each 10 minute duration. Here is sample output during maintenance. I also list some process info. Dual cpu plus HT with max degree of parallism set to 2. My take on this is that either 1) the cpu cache being shared via HT is a problem or 2) the CXPACKET and LATCH waits don't count because IO_COMPLETION indicates we are really waiting on disk. One thread gets the disk IO while the others wait?
PS I excluded OLEDB from the ***Total*** because it is erratic.
MonitorEndTime Duration WaitType Requests WaitTime Resource Signal AvgWaitTime %WaitTime %Signal
------------------- -------- -------------- -------- -------- -------- -------- ----------- --------- -------
2006-08-20 23:00:03 597746 ***Total*** 139113 953962 949811 4151 6 100.00 0.44
2006-08-20 23:00:03 597746 CXPACKET 32252 338975 338460 515 10 35.53 0.05
2006-08-20 23:00:03 597746 PAGEIOLATCH_SH 51360 314516 313813 703 6 32.97 0.07
2006-08-20 23:00:03 597746 IO_COMPLETION 19680 97254 97239 15 4 10.19 0.00
2006-08-20 23:00:03 597746 NETWORKIO 4176 75469 75469 0 18 7.91 0.00
2006-08-20 23:00:03 597746 PAGEIOLATCH_EX 4324 56368 56368 0 13 5.91 0.00
2006-08-20 23:00:03 597746 LATCH_EX 19962 48575 45951 2624 2 5.09 0.28
2006-08-20 23:00:03 597746 WRITELOG 2230 11522 11475 47 5 1.21 0.00
2006-08-20 23:00:03 597746 LOGBUFFER 2881 9142 8940 202 3 0.96 0.02
2006-08-20 23:00:03 597746 LCK_M_S 2 1500 1500 0 750 0.16 0.00
2006-08-20 23:00:03 597746 PAGEIOLATCH_UP 119 328 313 15 2 0.03 0.00
2006-08-20 23:00:03 597746 PAGELATCH_UP 189 93 78 15 0 0.01 0.00
2006-08-20 23:00:03 597746 LATCH_SH 135 80 80 0 0 0.01 0.00
2006-08-20 23:00:03 597746 DBTABLE 1 62 62 0 62 0.01 0.00
2006-08-20 23:00:03 597746 PAGELATCH_SH 1576 47 47 0 0 0.00 0.00
2006-08-20 23:00:03 597746 PAGESUPP 61 31 16 15 0 0.00 0.00
2006-08-20 23:00:03 597746 MISCELLANEOUS 8 0 0 0 0 0.00 0.00
2006-08-20 23:00:03 597746 CMEMTHREAD 15 0 0 0 0 0.00 0.00
2006-08-20 23:00:03 597746 PAGELATCH_EX 57 0 0 0 0 0.00 0.00
2006-08-20 23:00:03 597746 EXCHANGE 85 0 0 0 0 0.00 0.00
2006-08-20 23:00:03 597746 Total 149432 3361792 2141952 1219840 22 352.40 127.87
2006-08-20 23:00:03 597746 RESOURCE_QUEUE 9436 1791104 1190624 600480 189 187.75 62.95
2006-08-20 23:00:03 597746 SLEEP 880 596768 1504 595264 678 62.56 62.40
2006-08-20 23:00:03 597746 WAITFOR 2 20000 0 20000 10000 2.10 2.10
2006-08-20 22:50:05 602323 ***Total*** 156508 1682182 1679410 2772 10 100.00 0.16
2006-08-20 22:50:05 602323 IO_COMPLETION 117332 745826 745654 172 6 44.34 0.01
2006-08-20 22:50:05 602323 CXPACKET 4019 658950 658919 31 163 39.17 0.00
2006-08-20 22:50:05 602323 PAGEIOLATCH_SH 12559 230453 230096 357 18 13.70 0.02
2006-08-20 22:50:05 602323 LATCH_EX 20126 30948 28784 2164 1 1.84 0.13
2006-08-20 22:50:05 602323 WRITELOG 791 8003 7971 32 10 0.48 0.00
2006-08-20 22:50:05 602323 PAGEIOLATCH_EX 229 6014 6014 0 26 0.36 0.00
2006-08-20 22:50:05 602323 NETWORKIO 956 784 784 0 0 0.05 0.00
2006-08-20 22:50:05 602323 LOGBUFFER 32 466 466 0 14 0.03 0.00
2006-08-20 22:50:05 602323 PAGEIOLATCH_UP 34 346 346 0 10 0.02 0.00
2006-08-20 22:50:05 602323 PAGELATCH_EX 51 235 235 0 4 0.01 0.00
2006-08-20 22:50:05 602323 PAGELATCH_UP 261 94 94 0 0 0.01 0.00
2006-08-20 22:50:05 602323 PAGELATCH_SH 81 47 31 16 0 0.00 0.00
2006-08-20 22:50:05 602323 LATCH_SH 8 16 16 0 2 0.00 0.00
2006-08-20 22:50:05 602323 OLEDB 24 0 -2560 2560 0 0.00 0.15
2006-08-20 22:50:05 602323 CMEMTHREAD 6 0 0 0 0 0.00 0.00
2006-08-20 22:50:05 602323 MISCELLANEOUS 3 0 0 0 0 0.00 0.00
2006-08-20 22:50:05 602323 PAGESUPP 18 0 0 0 0 0.00 0.00
2006-08-20 22:50:05 602323 EXCHANGE 2 0 0 0 0 0.00 0.00
2006-08-20 22:50:05 602323 Total 159780 4145152 2910464 1234688 25 246.42 73.40
2006-08-20 22:50:05 602323 RESOURCE_QUEUE 2644 1840256 1233728 606528 696 109.40 36.06
2006-08-20 22:50:05 602323 SLEEP 604 603264 704 602560 998 35.86 35.82
2006-08-20 22:50:05 602323 WAITFOR 2 20016 0 20016 10008 1.19 1.19
MonitorTime spid kpid blocked waittype waittime lastwaittype cpu physical_io memusage ecid open_tran
------------------- ---- ---- ------- -------- -------- -------------- ------ ----------- -------- ---- ---------
2006-08-20 22:42:00 58 3424 0 0x0000 0 PAGEIOLATCH_SH 20828 1305435 0 1 1
2006-08-20 22:42:00 58 2844 58 0x0422 625 PAGEIOLATCH_SH 1375 1305435 0 2 1
2006-08-20 22:42:00 58 3468 0 0x0208 47406 CXPACKET 813167 1305434 0 0 1
MonitorTime spid kpid status program cmd InputBuffer
------------------- ---- ---- -------- -------- ---- --------------------------------------------------------------------
2006-08-20 22:42:00 58 3424 runnable SQLDMO_1 DBCC NULL
2006-08-20 22:42:00 58 2844 sleeping SQLDMO_1 DBCC NULL
2006-08-20 22:42:00 58 3468 sleeping SQLDMO_1 DBCC dbcc dbreindex(N'[dbo].[minute_fill_in]', N'', 0, sorted_data_reorg)
RandyHelpdesk: Perhaps Im not the only one that does not know what you are doing. 😉
-
yeah I'd worry about i/o completion, that's one wait type you don't want to see. essentially means slow disk subsystem.
[font="Comic Sans MS"]The GrumpyOldDBA[/font]
www.grumpyolddba.co.uk
http://sqlblogcasts.com/blogs/grumpyolddba/ -
dratt - sorry - meant to say essentially what you're doing is what I do, however rank your waits as a %age of the total wait to see if they are that significant.
[font="Comic Sans MS"]The GrumpyOldDBA[/font]
www.grumpyolddba.co.uk
http://sqlblogcasts.com/blogs/grumpyolddba/ -
The IO_COMPLETION is about 10% and 40% of the wait in the two ten minute durations. The CXPACKET and PAGELATCH_SH are about 75% and 55% in the same two durations. Are the CXPACKET and PAGELATCH_SH waits indicating that the overhead of threads is hurting performance? Or is this just a side effect of the work being done on another thread?
I think this machine has a set of mirrored pairs. I expected disk IO to be a bottle neck, not CXPACKET and PAGELATCH_SH. I'm have not analyzed the waitstats info before. I'm hoping to learn from this. If I can easily improve performance this machine without new hardware, that would be nice too.
RandyHelpdesk: Perhaps Im not the only one that does not know what you are doing. 😉
Viewing 12 posts - 1 through 11 (of 11 total)
You must be logged in to reply to this topic. Login to reply