4

UPDATE

In the comments under Aaron's post is an extensive explanation why I want to find this out, please read it if you want to know.

The system is running some ETL, reporting services and a replication subscription. SQL engine is 2012. The situation described below is continues, after a reboot it start within 5 minutes it start and never goes away. Even when no user are connected, no SSIS running, no reports being served and replication suspended this happens.

The reason i'm trying to get to the bottom of this is because on 1 system only I have a nonsensical wait ticking for 20 seconds every minute, while there is nothing running aside from the server instance itself and my ssms window. At the same time trying to work with heavy CLR operations (outer apply some custom clr to a large dataset for example) the processing time has increased from ~20 seonds to ~20 minutes.

These custom assemblies have all been unloaded, server rebooted but the waits keep coming.

wait_type                                                    waiting_tasks_count  wait_time_ms         max_wait_time_ms     signal_wait_time_ms
------------------------------------------------------------ -------------------- -------------------- -------------------- --------------------
CLR_AUTO_EVENT                                               21178                269767282            1817841              1117
CLR_SEMAPHORE                                                4704                 83518913             20051                180
CLR_MANUAL_EVENT                                             58                   377                  109                  0
CLR_TASK_START                                               2376                 376                  13                   136

The above number are from running the server for ~24 hours with very minimal use of ssis/ssrs and adhoc queries.

/UPDATE

Since a few weeks I have a continues increasing waittime for this specific wat situation:

name            wait_info
timestamp       38:57.3
wait_type       CLR_SEMAPHORE
opcode          Begin
duration        0
signal_duration 0
callstack       NULL
collect_current_thread_id   1888
event_sequence  249
last_error      0
client_connection_id    00000000-0000-0000-0000-000000000000
client_pid      0
is_system       FALSE
nt_username 
query_hash      0
session_id      0
session_nt_username 
transaction_id  0
request_id      0
query_plan_hash 0
scheduler_id    2

It fires every ~50 seconds, waits for 20 seconds and then drops. The only place this shows is in activity monitor "waiting tasks" and in the grouped "Resource Waits" but finding details beyond that proved difficult. Eventually I made this extended event and caught the little bugger, but I still don't have a clue where this comes from and how to fix it. Anyone that can point me to some documentation would be greatly appreciated.

create EVENT SESSION [InvestigateWaits] on server add EVENT sqlos.wait_info (
ACTION(package0.collect_current_thread_id
    , package0.event_sequence
    , package0.last_error
    , package0.process_id
    , sqlos.scheduler_address
    , sqlos.scheduler_id
    , sqlos.system_thread_id
    , sqlserver.client_app_name
    , sqlserver.client_connection_id
    , sqlserver.client_hostname
    , sqlserver.client_pid
    , sqlserver.context_info
    , sqlserver.database_name
    , sqlserver.is_system
    , sqlserver.nt_username
    , sqlserver.plan_handle
    , sqlserver.query_hash
    , sqlserver.query_plan_hash
    , sqlserver.request_id
    , sqlserver.session_id
    , sqlserver.session_nt_username
    , sqlserver.session_resource_group_id
    , sqlserver.session_resource_pool_id
    , sqlserver.session_server_principal_name
    , sqlserver.sql_text
    , sqlserver.transaction_id
    , sqlserver.transaction_sequence
    , sqlserver.tsql_frame
    , sqlserver.tsql_stack
    , sqlserver.username) 
where ([package0].[equal_uint64]([wait_type], (223)))) add TARGET package0.ring_buffer
    with (
            MAX_MEMORY = 51200 KB
            , EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS
            , MAX_DISPATCH_LATENCY = 5 SECONDS
            , MAX_EVENT_SIZE = 0 KB
            , MEMORY_PARTITION_MODE = NONE
            , TRACK_CAUSALITY = off
            , STARTUP_STATE = off
            )
go
  • Since it's 2012 and you mention ETL, are you using SSIS? Specifically, the new SSISDB? CLR is required for that to work and when you create the catalog, you have the opportunity to specify that a proc should run on server startup. Perhaps you've selected that for one instance and not in others – billinkc Nov 26 '14 at 14:58
  • @billinkc I like your thinking, do you know of any safe way to temporary disable ssisdb so I can test this? – Tristan Nov 26 '14 at 19:00
  • Guessing it's an inversion of the installation so EXEC master..sp_procoption N'sp_ssis_startup', 'startup', 'off' – billinkc Nov 26 '14 at 19:04
3

Stop worrying about timer/queue waits like CLR_SEMAPHORE. These waits always accumulate wait time, but this is not "bad" wait time in 99.999% of all cases. You should be filtering them out of your analysis and focusing on the ones that matter and that you can do anything about anyway. Use Paul Randal's NOT IN list as a guide:

  • I know this is usually not a thing to pay attention to. However this behavior only showing on 1 of several servers I have and it annos me thoroughly that I can't understand what the hell is going on. – Tristan Nov 25 '14 at 16:26
  • I'd have to understand the differences between the systems to start poking at guesses. Off the top of my head I'd suggest this system uses more CLR than the others - but that could mean a whole lot of things, so not overly useful. Also see this thread. – Aaron Bertrand Nov 25 '14 at 16:41
  • Thank you for the link, this atleast explains why this runs on spid 0. I updated the question with some more informatation about the setup and situation. If you would look at it I would really appreciate it. – Tristan Nov 26 '14 at 8:18
  • I'm still not sure what the actual problem is that you're trying to solve. You have high CLR_SEMAPHORE waits; is that the extent of the problem? Is it causing an actual performance issue? If so, how have you identified this wait as the (sole) culprit? If not, what are you solving? You know there will always be a highest wait, right? – Aaron Bertrand Nov 26 '14 at 12:23
  • The reason i'm trying to get to the bottom of this is because on 1 system only I have a nonsensical wait ticking for 20 seconds every minute, while there is nothing running aside from the server instance itself and my ssms window. At the same time trying to work with heavy CLR operations (outer apply some custom clr to a large dataset for example) the processing time has increased from ~20 seonds to ~20 minutes. – Tristan Nov 26 '14 at 12:28

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.