tsunami

log in
history

SQL2005: login logging

Luke Breuer
2010-04-17 01:39 UTC

introduction
It can be useful to record when users log in and out, and record how many resources they used. This is essentially the "parent table" of connection_id, a column used in both zs_Bandwidth_Log and zs_Connection_Resource_Usage_Log.

I have not tested this yet, but this table may also be useful in identifying connection attempts that failed due to DB server resources being pegged. For example, if someone is pegging the cpu and disk, someone may just give up on loading a particular application. That might show up in the log as an entry with the right program_name, but not enough cpu or reads.
notes on using SQL Server Broker
There is a DDL login trigger, but there are a few problems:
  1. as far as I can tell, it only fires on logon, not logoff
  2. if the code in it fails, users cannot log in
  3. if there is an contention for the logging table, logins get delayed

SQL Server Broker event notifications, on the other hand, fire asynchronously.
SQL code
table definition & initial values
drop table dbo.zs_Login_Logout_Log
create table dbo.zs_Login_Logout_Log (
    connection_id         uniqueidentifier    not null,
    session_id            smallint            not null,
    login_name            nvarchar(128)       not null,
    host_name             nvarchar(128)           null,
    client_net_address    varchar(48)             null,
    program_name          nvarchar(128)       not null,
    login_datetime        datetime            not null,
    logout_datetime       datetime                null,
    reads                 bigint                  null,
    writes                bigint                  null,
    cpu                   bigint                  null,
    --login_xml             xml,
    --logout_xml            xml,
    
    primary key nonclustered (connection_id),
    unique clustered (login_datetime, connection_id)
) 
go

insert  zs_Login_Logout_Log(connection_id, session_id, login_name, host_name, 
                            client_net_address, program_name, login_datetime /*, login_xml*/)
select  c.connection_id,
        s.session_id, 
        s.original_login_name,
        s.host_name,
        c.client_net_address,
        s.program_name,
        s.login_time
        --,@message_body
from    sys.dm_exec_connections c
inner join sys.dm_exec_sessions s on s.session_id = c.session_id
where   s.original_login_name != 'NT AUTHORITY\SYSTEM'
    or  s.program_name like 'SQLAgent - TSQL JobStep%'
preparation for using SQL Server Broker
-- needs to be run as a DB admin
use your_database
go
alter database your_database set trustworthy on;
alter database your_database set enable_broker;
go
It would appear that at least one of these requires an exclusive lock on the DB as a whole, although I have not completely verified this.
SQL Server Broker code
Note that I exclude operations that the server does itself (@login_name = 'NT AUTHORITY\SYSTEM'), unless it is running a job.

Documentation for:
-- needs to be run as a DB admin
/*
drop service Login_Logout_Log_Service
drop queue Login_Logout_Log_Queue
drop procedure zs_Login_Logout_Log_Event
drop event notification Login_Logout_Log_Notification on server
*/

create queue dbo.Login_Logout_Log_Queue
go

create service Login_Logout_Log_Service
authorization dbo
on queue Login_Logout_Log_Queue
([http://schemas.microsoft.com/SQL/Notifications/PostEventNotification])
go

create event notification Login_Logout_Log_Notification
on server
for audit_login, audit_logout
to service 'Login_Logout_Log_Service', 'current database'
go

set ansi_nulls on
go
set quoted_identifier on
go

create procedure dbo.zs_Login_Logout_Log_Event
as
set nocount on

declare     @message_body xml,
            @message_type_name nvarchar(256),
            @dialog uniqueidentifier;

while (1 = 1)
begin
    -- receive the next available message
    waitfor (
        receive top(1)
            @message_type_name = message_type_name,
            @message_body = message_body,
            @dialog = conversation_handle
        from Login_Logout_Log_Queue
    ), timeout 2000

    if (@@rowcount = 0)
        break;

    if (@message_type_name = 'http://schemas.microsoft.com/SQL/ServiceBroker/EndDialog')
    begin
        print 'End Dialog received for dialog # ' + cast(@dialog as nvarchar(40)) 
        end conversation @dialog 
        break;
    end 

    declare @spid int
    declare @event_type varchar(64)
    declare @start_time datetime
    declare @login_name varchar(64)
    declare @program_name varchar(128)
    declare @success bit

    set @login_name = @message_body.value('(/EVENT_INSTANCE/LoginName)[1]', 'varchar(64)')
    set @success = @message_body.value('(/EVENT_INSTANCE/Success)[1]', 'bit')
    set @program_name = @message_body.value('(/EVENT_INSTANCE/ApplicationName)[1]', 'varchar(128)')

    if (@login_name = 'NT AUTHORITY\SYSTEM' and @program_name not like 'SQLAgent - TSQL JobStep%') or @success = 0
        break

    set @spid  = @message_body.value('(/EVENT_INSTANCE/SPID)[1]', 'int')
    set @event_type = @message_body.value('(/EVENT_INSTANCE/EventType)[1]', 'varchar(64)')
    set @start_time = @message_body.value('(/EVENT_INSTANCE/StartTime)[1]', 'datetime')

    if @event_type = 'AUDIT_LOGIN'
    begin
        insert  zs_Login_Logout_Log(connection_id, session_id, login_name, host_name, 
                                    client_net_address, program_name, login_datetime /*, login_xml*/)
        select  c.connection_id,
                s.session_id, 
                @login_name,          -- s.original_login_name
                s.host_name,
                c.client_net_address,
                s.program_name,
                @start_time           -- s.login_time
                --,@message_body
        from    sys.dm_exec_connections c
        inner join sys.dm_exec_sessions s on s.session_id = c.session_id
        where   c.session_id = @spid
    end
    else if @event_type = 'AUDIT_LOGOUT'
    begin
        update  zs_Login_Logout_Log set
                logout_datetime = @message_body.value('(/EVENT_INSTANCE/EndTime)[1]', 'datetime'),
                reads           = @message_body.value('(/EVENT_INSTANCE/Reads)[1]', 'bigint'),
                writes          = @message_body.value('(/EVENT_INSTANCE/Writes)[1]', 'bigint'),
                cpu             = @message_body.value('(/EVENT_INSTANCE/CPU)[1]', 'bigint')
                --,logout_xml = @message_body
        where   session_id = @spid
            and login_datetime = @start_time
    end
end
go


alter queue Login_Logout_Log_Queue
with activation (
    status = on,
    procedure_name = zs_Login_Logout_Log_Event,
    max_queue_readers = 2, execute as self)