Sql-server – Find reason long running stored proc SQL Server

profilersql serversql-server-2008-r2

I have a stored proc which is called every 2.5 seconds by a program, 24-7.
This proc normally runs under the 10 milliseconds. A few times a day (3 -5 times) it takes around 42953 milliseconds to run (always between 42950 and 42959 milliseconds).

How can I find or profile the reason why it takes so long?

Update:
Sql server version 2008 R2

Procedure:

select 
    [view_EventsToRaise].EventId,
    [view_EventsToRaise].EventStatus,
    [view_EventsToRaise].Tag,
    [view_EventsToRaise].SessieGebruikerId,
    Postbus.Persoon_Id_afz      as PersoonIdAfz,
    Postbus.Persoon_Id_adr      as PersoonIdAdr,
    Postbus.Persoon_Id_derde    as PersoonIdDerde,
    Postbus.Locatie_Id          as LocatieId,
    Postbus.Artikel_Id          as ArtikelId,
    Postbus.Onderwerp_Id        as OnderwerpId,
    Postbus.Bedrijf_Id_afz      as BedrijfIdAfz,
    Postbus.Bedrijf_Id_adr      as BedrijfIdAdr,
    Postbus.Bedrijf_Id_derde    as BedrijfIdDerde,
    Postbus.Document_Id         as DocumentId,      
    Postbus.Document            as Document,        
    DataKenmerk.Code            as PostbusDataCode,
    PostbusData.Inhoud          as PostbusDataInhoud,
    SimObj.Id                   as SimObjId,
    Eventsoort.Code             as Eventsoort
from 
    [view_EventsToRaise]
    left outer join Postbus
        left outer join PostbusData
            inner join DataKenmerk
            on PostbusData.DataKenmerk_id = DataKenmerk.id
        on PostbusData.Postbus_Id = Postbus.id
    on Postbus.Id = [view_EventsToRaise].PostbusId
    left outer join SimObjEvent                         
        inner join eventsoort
        on eventsoort.id = SimObjEvent.eventsoort_id
    on [view_EventsToRaise].SimObjEventId = SimObjEvent.Id
    left outer join SimObj
    on SimObj.Id = SimObjEvent.SimObj_Id
order by
    [view_EventsToRaise].Tijd,
    [view_EventsToRaise].EventId

Update 29-9-2014:
When the above described situation occurs, looking to the profiler, the following got mine attention:
When the RPC:Completed event is registered, the the starttime is the current system time at the log moment, but the endtime is a value in the future (current system time plus the duration, approx. 43 sec in the future).

How is the value of the endtime column determined?
Is this a prediction?

Best Answer

This is probably caused by a blocking process. 3-5 times a day this is blocked by some update or other write that takes ~40 seconds. Your SELECT blocks until it can continue. If this is indeed the case, the problem can be identified using the Blocked Process Report Event. You will have to enable this event and set the threshold to ~35 seconds. See blocked process threshold Server Configuration Option. Obviously the event may fire for other queries too, but arguable those issues also needs to be addressed.

A simple workaround for blocking is using a row versioned isolation level. Read Understanding Row Versioning-Based Isolation Levels.

Otherwise, you will need to investigate this as a performance problem. Read How to analyse SQL Server performance.