Login Trigger Causing Deadlocks

  • Background:

    In my environment historically people have obtained elevated user ID information and use it for their logins or have it set for use in applications such as report server. We are trying to track and get these elevated IDs out of the hands of those who should not have them. Our answer is a Login Trigger which logs the elevated user we chose to monitor. It checks the TrackedLogins table to see if that user is supposed to be monitored and the TrackedServerExcludes table to determine if this login from this host should be tracked. The info is logged to a table and and email is sent to the DBA group, if warranted (SA gets emailed but other service accounts just get logged). We review the email or table and track down the offender to have them change the account they are using.

    The trigger works fine except that it causes a deadlock on one of my servers. This particular server is being connected to be a Reporting server that is using the SA account. While we are waiting for the slow moving bureaucracy to change the account, I am watching many, many logins from this server for the SA account. It causes multiple deadlocks a day but never seems to not be able to get in, as it immediately retries.

    I wrapped the trigger content in a transaction to make a subsequent trigger call wait until the previous call was done, but that has not helped. I am trying to figure out what else I can do, especially since this is not a long-running script. It is not causing a major lockout of connectiing users, but is logging these messages and I'd like to get rid of them.

    Errors:

    Error 17892 Severity 20 State 1 Logon failed for login 'sa' due to trigger execution CLIENT 10 221 176 61

    Error 18056 Severity 20 State 1 The client was unable to reuse a session with SPID 64 which had been reset for connection pooling This error may have been caused by an earlier operation failing Check the error logs for failed operations immediately before this error message

    Error 1205 Severity 13 State 51 Transaction Process ID 64 was deadlocked on lock resources with another process and has been chosen as the deadlock victim Rerun the transaction

    Trigger:

    Alter TRIGGER LoginDetectionTrigger

    ON ALL SERVER WITH EXECUTE AS 'sa'

    FOR LOGON

    AS

    BEGIN

    Begin Tran

    --Make sure the required tables exist in the Master DB before proceeding.

    If Object_ID('LoginTracker') Is Not Null

    And Object_ID('TrackedLogins') Is Not Null

    And Object_ID('TrackedServerExcludes') Is Not Null

    Begin

    --Print 'Tables exist'

    --Select ORIGINAL_LOGIN()

    If (ORIGINAL_LOGIN() In(Select [LoginName] from TrackedLogins where [Tracked] = 1) --If it is a tracked login....

    And(Select Top 1 [HOST_NAME] from sys.dm_exec_sessions Where [is_user_process] = 1

    And original_login_name In(Select [LoginName] from [TrackedLogins] where [Tracked] = 1)) Is Not Null) --And the process is a user process....

    Begin

    --Print 'It is a tracked login'

    If (

    ((Select UseExcludes From TrackedLogins Where LoginName = ORIGINAL_LOGIN()) = 1) --If Use Excludes flag is on...

    And HOST_NAME() Not In(Select ServerName From TrackedServerExcludes)) --And the host name not in the exclude list...

    Or ((Select UseExcludes From TrackedLogins Where LoginName = ORIGINAL_LOGIN()) = 0) --Or the Use Excludes flag is off....

    Begin

    --Print 'Logging data'

    Declare @body1 Nvarchar(1000)

    Declare @Subject NVarChar(100)

    Declare @data XML

    Declare @HostName VarChar(25), @LoginName VarChar(255), @Client VarChar(100), @PostTime Datetime, @ProgramName VarChar(255), @SessionID Int, @TrackerID BigInt

    Insert Into LoginTracker(LoginName, SessionID, PostTime, HostName, Client, ProgramName)

    Select Top 1 S.[original_login_name], S.[session_id], S.[login_time], S.[host_name], S.[client_interface_name], S.[program_name]

    From sys.dm_exec_sessions S

    Left Join LoginTracker L On S.[session_id] = L.[SessionID] And S.[login_time] = L.[PostTime]

    Inner Join TrackedLogins T On S.[original_login_name] = T.[LoginName]

    Where

    S.original_login_name = Original_Login()

    And T.Tracked = 1 --Make sure we want to track this login.

    And S.is_user_process = 1 --Don't want any local system processes.

    And S.text_size > 0 --Another system process preventer.

    And L.SessionID Is Null --Joined table value must be null to insert this record into the table. Prevents dupes.

    Order By S.login_time Desc

    Select Top 1 @TrackerID = L.TrackerID, @LoginName = ORIGINAL_LOGIN(), @SessionID = SessionID, @HostName = HostName, @Client = Client, @ProgramName = ProgramName, @PostTime = PostTime

    From LoginTracker L

    Inner Join TrackedLogins T On L.LoginName = T.LoginName

    Where Reported Is Null

    And Notify = 1

    And T.LoginName = ORIGINAL_LOGIN()

    If @SessionID Is Not Null

    Begin

    --Print 'Sending email'

    Update LoginTracker Set Reported = 1 Where TrackerID = @TrackerID

    Set @body1 = 'Server: '+@@servername+ '.

    SQL Server login tracker detected a login you requested notification for at: ' + IsNull(Convert(VarChar(30), @Posttime, 114), '') + ',

    using login ID: ' + @LoginName + ', from client address: ' + IsNull(@HostName, '') + ', using program: ' + IsNull(@ProgramName, '') + ', ' + IsNull(@Client, '') + '.'

    Print @body1

    Set @Subject = 'Server: '+@@servername+' SQL Server Tracked Login Detected For ' + @LoginName + ', From: ' + @HostName + '.'

    EXEC msdb.dbo.sp_send_dbmail @recipients='HISDBA@ACS-Inc.com', --ALTER HERE HISDBA

    @subject = @Subject,

    @body = @body1,

    @body_format = 'HTML',

    @importance = 'High'

    End

    --Here we set the Reported value for columns where the Reported value is Null but the login is not supposed to be reported.

    --This is so we have no confusion as to whether to report the login, or think it was forgotten.

    Update L

    Set [Reported] = 0

    From [LoginTracker] L

    Inner Join [TrackedLogins] T On L.LoginName = T.[LoginName]

    Where Reported Is Null

    And [Notify] = 0

    End

    End

    End

    Else

    RaisError ('One of the tables for the login trigger does not exist. Trigger is disabled until all tables do exist, in the Master DB.', 10, 1) With Log;

    Commit Tran

    END;

    Tables involved:

    IF Not EXISTS (SELECT * FROM sys.objects WHERE object_id = OBJECT_ID(N'[dbo].[LoginTracker]') AND type in (N'U'))

    Begin

    Create Table LoginTracker (TrackerID Int Identity(1,1) Not Null, LoginName VarChar(255) Not Null, SessionID Int, PostTime Datetime,

    HostName VarChar(25), Client VarChar(100), ProgramName VarChar(255), LoginStatus VarChar(30), Reported Int Null, LastChange datetime NULL) On [Primary]

    Create Clustered Index PKLoginTracker On LoginTracker

    (SessionID ASC, PostTime ASC)

    On [Primary]

    ALTER TABLE dbo.LoginTracker ADD CONSTRAINT

    DF_LoginTracker_LastChange DEFAULT GetDate() FOR LastChange

    End

    IF Not EXISTS (SELECT * FROM sys.objects WHERE object_id = OBJECT_ID(N'[dbo].[TrackedLogins]') AND type in (N'U'))

    Begin

    Create Table TrackedLogins (TrackedID Int Identity(1,1) Not Null, LoginName VarChar(255) Not Null,

    Tracked Bit Not Null, Notify Bit Not Null, UseExcludes Bit Not Null, LastChange datetime NULL

    ) On [Primary]

    ALTER TABLE dbo.TrackedLogins ADD CONSTRAINT

    PKTrackedLogins PRIMARY KEY NONCLUSTERED

    (

    LoginName ASC

    ) WITH( STATISTICS_NORECOMPUTE = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]

    ALTER TABLE dbo.TrackedLogins ADD CONSTRAINT

    DF_TrackedLogins_LastChange DEFAULT GetDate() FOR LastChange

    End

    IF Not EXISTS (SELECT * FROM sys.objects WHERE object_id = OBJECT_ID(N'[dbo].[TrackedServerExcludes]') AND type in (N'U'))

    Begin

    Create Table TrackedServerExcludes (TrackerID Int Identity(1,1) Not Null, ServerName VarChar(255) Not Null, LastChange datetime NULL) On [Primary]

    Create Clustered Index PKTrackedServerExcludes On TrackedServerExcludes

    (ServerName ASC)

    On [Primary]

    ALTER TABLE dbo.TrackedServerExcludes ADD CONSTRAINT

    PK_TrackedServerExcludes PRIMARY KEY NONCLUSTERED

    (

    ServerName

    ) WITH( STATISTICS_NORECOMPUTE = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]

    End

    Thanks,

    Chris

    Learning something new on every visit to SSC. Hoping to pass it on to someone else.

  • Can you post the deadlock graph?

    Gail Shaw
    Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
    SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • Stamey (10/2/2014)


    We are trying to track and get these elevated IDs out of the hands of those who should not have them.

    Gosh, this sounds like it's really out of hand and fixing it once won't prevent it in the future. I'd recommend that the company 1) initiate a company policy where people can be fired for using someone/something else's login, make it well known, and enforce it and 2) start taking such logins seriously by changing the passwords on a regular basis.

    --Jeff Moden


    RBAR is pronounced "ree-bar" and is a "Modenism" for Row-By-Agonizing-Row.
    First step towards the paradigm shift of writing Set Based code:
    ________Stop thinking about what you want to do to a ROW... think, instead, of what you want to do to a COLUMN.

    Change is inevitable... Change for the better is not.


    Helpful Links:
    How to post code problems
    How to Post Performance Problems
    Create a Tally Function (fnTally)

  • Jeff,

    In a perfect world this never would have happened. In my world, ruled by management, I can only be as heavy-handed as they will allow me. My first suggestion was to change the PW on the SA accounts and the login failure be damned, but I was immediately overruled and told we had to go about this in a softer fashion. Not my battle. I do what I am told.

    GilaMonster,

    What do you expect here? Are you wanting a screen shot of the graph or do you want me to attach the XDL files?

    Thanks,

    Chris

    Learning something new on every visit to SSC. Hoping to pass it on to someone else.

  • Stamey (10/2/2014)


    Jeff,

    In a perfect world this never would have happened. In my world, ruled by management, I can only be as heavy-handed as they will allow me. My first suggestion was to change the PW on the SA accounts and the login failure be damned, but I was immediately overruled and told we had to go about this in a softer fashion. Not my battle. I do what I am told.

    Ah, understood. I hate it when that happens. I worked for a company that was like that and I kept a sign taped to the back of my chair after the first time management made such an edict. It's called the "Conductors Poem".

    It's not my job to drive the train,

    Nor even ring the bell,

    But let the damned thing jump the track,

    And watch who catches hell.

    To be honest, the world doesn't have to be perfect for management to come to their senses and start listening to the pros they hired. That's one of the reasons I elected to no longer work for that particular company. I wasn't looking for perfection... I was just trying to avoid total insanity.

    --Jeff Moden


    RBAR is pronounced "ree-bar" and is a "Modenism" for Row-By-Agonizing-Row.
    First step towards the paradigm shift of writing Set Based code:
    ________Stop thinking about what you want to do to a ROW... think, instead, of what you want to do to a COLUMN.

    Change is inevitable... Change for the better is not.


    Helpful Links:
    How to post code problems
    How to Post Performance Problems
    Create a Tally Function (fnTally)

  • Ok.... I've studied your code and tables a bit. Let's peel one potato at a time...

    First, I see no need for the explicit transaction. Getting rid of that will likely solve a good number of the deadlocks especially since this is a relatively very long transaction with lot's of interaction with key tables, not to mention some nasty built in performance problems and super repetitive code.

    On those notes...

    1. Get rid of the explicit transaction.

    2. Consider getting all of the information from the TrackedLogins table at once and storing the single row result in either a temporary table or some variables that have the correct datatypes. The RBAR of variables might prove useful, in this case.

    3. Consider getting all of the information from sys.dm_exec_sessions at once and storing it in a similar fashion.

    4. Consider making your own tables with datatypes that match the items being returned from the ORIGINAL_LOGIN() function and sysmdm_exec_sessions so there is no datatype mismatch on your joins so that any queries will actually be able to use indexes instead of doing table scans.

    5. Consider using the proper 2 part naming convention for all tables for a bit of extra performance.

    6. Consider consolidating all of your DECLAREs as a single DECLARE of multiple variables. Do the same in steps 2 and 3 above with your SELECTs to set multiple variable from a single SELECT.

    7. Consider NOT doing the check for table existence at the beginning. Ostensibly, the person installing the trigger should have already verified that they exist. It's a total waste of clock cycles to keep checking for such a thing for every login.

    8. Make sure that you got rid of that bloody explicit transaction.

    9. Consider running your code through a formatter to make troubleshooting easier.

    10. Make sure that you have the appropriate indexes on tables that have the correct data-types so you can stop the table scans.

    11. Have you gotten rid of that bloody explicit transaction, yet? 😉

    --Jeff Moden


    RBAR is pronounced "ree-bar" and is a "Modenism" for Row-By-Agonizing-Row.
    First step towards the paradigm shift of writing Set Based code:
    ________Stop thinking about what you want to do to a ROW... think, instead, of what you want to do to a COLUMN.

    Change is inevitable... Change for the better is not.


    Helpful Links:
    How to post code problems
    How to Post Performance Problems
    Create a Tally Function (fnTally)

  • Stamey (10/2/2014)


    What do you expect here?

    The deadlock graph, the entire thing. Without being able to see exactly what objects, indexes, locks, statements, etc were involved in the deadlock, it's near-impossible to fix it.

    Gail Shaw
    Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
    SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • Here are three images. Is this what you need?

    Jeff,

    I am reviewing your suggestions and trying to implement them today.

    Thanks,

    Chris

    Learning something new on every visit to SSC. Hoping to pass it on to someone else.

  • Stamey (10/3/2014)


    Here are three images. Is this what you need?

    No, or I'd have asked for pictures of the deadlock graph 😉

    https://www.simple-talk.com/sql/performance/sql-server-deadlocks-by-example/

    Gail Shaw
    Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
    SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • I am not familiar with what a deadlock graph looks like, so I'm kind of in the dark here. I looked at that article and what is described as a graph there, I have never seen before, so I'm learning new stuff here. Anyway, the problem server is a 2005 box so I have to find a different way. I captured several with Profiler, and they are XDL files.

    Thanks,

    Chris

    Learning something new on every visit to SSC. Hoping to pass it on to someone else.

  • Great, so post them please. Pictures of SSMS's graphical rendition of the deadlock graph files is useless as it's only part of the information. Hence why I asked for the entire thing.

    Gail Shaw
    Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
    SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability

    We walk in the dark places no others will enter
    We stand on the bridge and no one may pass
  • OK, here are three. I had to change the extension to upload them. SSC does not allow XDL files.

    Thanks,

    Chris

    Learning something new on every visit to SSC. Hoping to pass it on to someone else.

Viewing 12 posts - 1 through 11 (of 11 total)

You must be logged in to reply to this topic. Login to reply