Blog Post

IP and Default Trace…T-SQL Tuesday #005 - A week early - D'oh

,

As chance would have it, I had been checking Adam’s blog daily for the last few days to find the next T-SQL Tuesday.  Not having seen it, I started working on my next post yesterday evening.  The fortunate thing is that the post I was working on fits well with this months topic.  T-SQL Tuesday #005 is being hosted by Aaron Nelson.  And now I have one more blog to bookmark since I didn’t have his bookmarked previously.

This month the topic is Reporting.  Reporting is a pretty wide open topic but not nearly as wide open as the previous two months.  Nonetheless, I think the topic should be handled pretty easily by most of the participants.  My post deals with reporting on User connections.  I have to admit that this one really just fell into my lap as I was helping somebody else.

The Story

Recently I came across a question on how to find the IP address of a connection.  From experience I had a couple of preconceptions on what could be done to find this information.  SQL server gives us a few avenues to be able to find that data.  There are also some good reasons to try and track this data as well.  However, the context of the question was different than I had envisioned it.  The person already knew how to gain the IP address and was already well onto their way with a well formed query.  All that was needed was just the final piece of the puzzle.  This final piece was to integrate sys.dm_exec_connections with the existing query which pulls information from trace files that exist on the server.

After exploring the query a bit, it also became evident that other pertinent information could prove quite useful in a single result set.  The trace can be used to pull back plenty of useful information depending on the needs.  Here is a query that you can use to explore that information and determine for yourself the pertinent information for your requirements, or if the information you seek is even attainable through this method.

SELECT *
 FROM sys.traces T
CROSS Apply ::FN_TRACE_GETTABLE(
CASE
WHEN CHARINDEX( '_',T.[PATH]) <> 0
THEN SUBSTRING(T.PATH, 1, CHARINDEX( '_',T.[PATH])-1) + '.trc'
ELSE T.[PATH]
END, T.max_files)

Now, I must explain that there is a problem with joining the trace files to the DMVs.  The sys.dm_exec_connections maintains current connection information as does the sys.dm_exec_sessions DMV.  Thus mapping the trace file to these DMV’s could be problematic if looking for historical information.  So now the conundrum is really how to make this work.  So that the data returned in the report, some additional constraints would have to be placed on the query.  But let’s first evaluate the first go around with this requirement.

Query Attempts

SELECT I.NTUserName,I.loginname,I.SessionLoginName,I.databasename
,EC.client_net_address AS SourceIPAddress,I.HostName, I.ApplicationName
,MIN(I.StartTime) AS ConnectionStart,MAX(I.StartTime) AS ConnectionEnd
,S.principal_id,S.sid,S.type_desc,S.name
FROM sys.traces T
CROSS Apply ::FN_TRACE_GETTABLE(
CASE
WHEN CHARINDEX( '_',T.[PATH]) <> 0
THEN SUBSTRING(T.PATH, 1, CHARINDEX( '_',T.[PATH])-1) + '.trc'
ELSE T.[PATH]
END, T.max_files) I
LEFT Outer Join sys.server_principals S
ON CONVERT(VARBINARY(MAX), I.loginsid) = S.sid
LEFT Outer Join sys.dm_exec_connections EC
ON EC.session_id = I.SPID
WHERE T.id = 1
And I.LoginSid IS not null
GROUP BY I.NTUserName,I.loginname,I.SessionLoginName,I.databasename,EC.client_net_address,I.HostName,I.ApplicationName
,I.StartTime,S.principal_id,S.sid,S.type_desc,S.name
HAVING DATEDIFF(dd, MAX(I.StartTime), GETDATE()) <= 30
ORDER BY databasename, loginname, I.StartTime

While evaluating this query, one may spot the obvious problem.  If not seen at this point, a quick execution of the query will divulge the problem.  SPIDs are not unique, they are re-used.  Thus when querying historical information against current running information, one is going to get inaccurate results.  Essentially, for this requirement we have no better certain knowledge what the IP Address would be for those connections showing up in the trace files.  The IP Addresses of the current connections will cross populate and render inaccurate results from the historical information.

My next step gets us a little closer.  I decided to include more limiting information in the Join to the sys.dm_exec_connections view.  The way I determined to do this was that I needed to also include the loginname as a condition.  Thus in order to get that, I need to include sys.dm_exec_sessions in my query.  To make it all come together, I pulled that information into a CTE.  Here is the new version.

WITH ConnectInfo AS (
SELECT ec.session_id, es.login_time,es.login_name,ec.client_net_address
FROM sys.dm_exec_connections ec
INNER Join sys.dm_exec_sessions es
ON ec.session_id = es.session_id
)
 
SELECT I.NTUserName,I.loginname,I.SessionLoginName,I.databasename
,EC.client_net_address AS SourceIPAddress,I.HostName, I.ApplicationName
,MIN(I.StartTime) AS ConnectionStart,MAX(I.StartTime) AS ConnectionEnd
,S.principal_id,S.sid,S.type_desc,S.name
FROM sys.traces T
CROSS Apply ::FN_TRACE_GETTABLE(
CASE
WHEN CHARINDEX( '_',T.[PATH]) <> 0
THEN SUBSTRING(T.PATH, 1, CHARINDEX( '_',T.[PATH])-1) + '.trc'
ELSE T.[PATH]
END, T.max_files) I
LEFT Outer Join sys.server_principals S
ON CONVERT(VARBINARY(MAX), I.loginsid) = S.sid
LEFT Outer Join ConnectInfo EC
ON EC.session_id = I.SPID
And EC.login_name = I.LoginName
WHERE T.id = 1
And I.LoginSid IS not null
GROUP BY I.NTUserName,I.loginname,I.SessionLoginName,I.databasename,EC.client_net_address,I.HostName,I.ApplicationName
,I.StartTime,S.principal_id,S.sid,S.type_desc,S.name
HAVING DATEDIFF(dd, MAX(I.StartTime), GETDATE()) <= 30
ORDER BY databasename, loginname, I.StartTime

The information pulled back is much cleaner now.  But wait, this mostly reflects current connections or connections from the same person who happens to have the same SPID as a previous time that person connected.  Yes, an inherent problem with combining historical information to the current connection information in the server.

Solution

My recommendation to solve this need for capturing IP address information along with the person who connected, their computer hostname, and the time that they connected is to do so pre-emptively.  (I know this diverges from the report for a minute, but is necessary to setup for the report).  A solution I have implemented in the past is to use a logon trigger that records the pertinent information to a Table.

Tables

SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO
SET ANSI_PADDING ON
GO
CREATE TABLE [dbo].[AuditLogonViolation](
[LogonVID] [INT] IDENTITY(1,1) NOT NULL,
[HOST] [VARCHAR](30) NULL,
[ViolationTime] [DATETIME] NULL,
[ServerName] [VARCHAR](30) NULL,
[LoginName] [VARCHAR](30) NULL,
[SIDValue] [VARCHAR](30) NULL,
[ClientHost] [VARCHAR](30) NULL,
[ErrorMessage] [VARCHAR](100) NULL,
 CONSTRAINT [PK__AuditLogonViolation] PRIMARY KEY CLUSTERED
(
[LogonVID] ASC
)WITH (PAD_INDEX  = OFF, STATISTICS_NORECOMPUTE  = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS  = ON, ALLOW_PAGE_LOCKS  = ON) ON [PRIMARY]
) ON [PRIMARY]
GO
SET ANSI_PADDING OFF
GO
SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO
SET ANSI_PADDING ON
GO
CREATE TABLE [dbo].[AuditLogonEvent](
[LogonEventID] [INT] IDENTITY(1,1) NOT NULL,
[HOST] [VARCHAR](30) NULL,
[EventType] [VARCHAR](100) NULL,
[EventTime] [DATETIME] NULL,
[SPID] [SMALLINT] NULL,
[ServerName] [VARCHAR](30) NULL,
[LoginName] [VARCHAR](30) NULL,
[LoginType] [VARCHAR](30) NULL,
[SID] [VARCHAR](30) NULL,
[ClientHost] [VARCHAR](30) NULL,
 CONSTRAINT [PK_LogonEventID] PRIMARY KEY CLUSTERED
(
[LogonEventID] ASC
)WITH (PAD_INDEX  = OFF, STATISTICS_NORECOMPUTE  = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS  = ON, ALLOW_PAGE_LOCKS  = ON) ON [SecData]
) ON [SecData]
GO
SET ANSI_PADDING OFF
GO

Trigger

SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO
 
CREATE TRIGGER [TrigAuditServerLogonEvent]
ON ALL SERVER
WITH EXECUTE AS 'SomeUser'
FOR LOGON
AS
 
DECLARE @DATA XML
 
SET @DATA = EVENTDATA()
IF (@DATA.VALUE('(/EVENT_INSTANCE/LoginName)[1]', 'varchar(30)') = 'acceptableappuser' and HOST_NAME() not in ('serverlist where that account may logon'))
BEGIN
ROLLBACK
INSERT INTO AdminDB.dbo.AuditLogonViolation (
HOST,ViolationTime,ServerName,LoginName,SIDValue,ClientHost,ErrorMessage
)
SELECT
HOST_NAME()
,@DATA.VALUE('(/EVENT_INSTANCE/PostTime)[1]', 'datetime')
,@DATA.VALUE('(/EVENT_INSTANCE/ServerName)[1]', 'varchar(30)')
,@DATA.VALUE('(/EVENT_INSTANCE/LoginName)[1]', 'varchar(30)')
,@DATA.VALUE('(/EVENT_INSTANCE/SID)[1]', 'varchar(30)')
,@DATA.VALUE('(/EVENT_INSTANCE/ClientHost)[1]', 'varchar(30)')
,'Login Violation - You are about to be ERASED!'
RAISERROR 500001 'Login with this User - not Permitted!'
END
ELSE
BEGIN
INSERT INTO AdminDB.dbo.AuditLogonEvent (
HOST
,EventType
,EventTime
,SPID
,ServerName
,LoginName
,LoginType
,SID
,ClientHost
)
SELECT
HOST_NAME()
,@DATA.VALUE('(/EVENT_INSTANCE/EventType)[1]', 'varchar(100)')
,@DATA.VALUE('(/EVENT_INSTANCE/PostTime)[1]', 'datetime')
,@DATA.VALUE('(/EVENT_INSTANCE/SPID)[1]', 'smallint')
,@DATA.VALUE('(/EVENT_INSTANCE/ServerName)[1]', 'varchar(30)')
,@DATA.VALUE('(/EVENT_INSTANCE/LoginName)[1]', 'varchar(30)')
,@DATA.VALUE('(/EVENT_INSTANCE/LoginType)[1]', 'varchar(30)')
,@DATA.VALUE('(/EVENT_INSTANCE/SID)[1]', 'varchar(30)')
,@DATA.VALUE('(/EVENT_INSTANCE/ClientHost)[1]', 'varchar(30)')
END
 
GO
SET ANSI_NULLS OFF
GO
SET QUOTED_IDENTIFIER OFF
GO
ENABLE TRIGGER [TrigAuditServerLogonEvent] ON ALL SERVER

This solution ignores the IP Address and just presents us with the HostName from where the logon occurred.  That should be enough to trace back to the source of the connection.  Also note that the application was not included in this, that is information that could be gained from the trace files.  What this does is create a structure for logging logon events as well as prevent logons from unauthorized sources using an account that has been compromised (while logging that action as well).  With this, I now have a solution that complements the trace file.  I could query both and create a more accurate report of the logon activity that has occurred historically (depending on retention policy etc.).  This last method is somewhat limited by the EventData function and the xml schema that comes with it.  You can check it out here.

Reports

So here are a couple of parting solutions that would be able to give us the relevant data for tracking these historical logons.

SELECT HOST,ViolationTime,NULL AS SPID,ServerName,LoginName,SIDValue,ClientHost,ErrorMessage,'LogonViolation' AS LogonType
FROM AuditLogonViolation
UNION All
SELECT HOST,EventTime,SPID,ServerName,LoginName,SID,ClientHost,EventType,'LogonSuccess' AS LogonType
FROM AuditLogonEvent

The above is a simple query to pull back the information from both the violations and successful logon audit tables.

The following is a solution for combining the previous requirement (as I have translated it to truly correlate to Host rather than IP).

WITH ConnectInfo AS(
SELECT HOST,EventType,EventTime,SPID,ServerName,LoginName,LoginType,SID,ClientHost
FROM AuditLogonEvent
)
 
SELECT I.NTUserName,I.loginname,I.SessionLoginName,I.databasename
,EC.ClientHost AS SourceIPAddress,I.HostName, I.ApplicationName
,MIN(I.StartTime) AS ConnectionStart,MAX(I.StartTime) AS ConnectionEnd
,EC.EventTime
,S.principal_id,S.sid,S.type_desc,S.name
FROM sys.traces T
CROSS Apply ::FN_TRACE_GETTABLE(
CASE
WHEN CHARINDEX( '_',T.[PATH]) <> 0
THEN SUBSTRING(T.PATH, 1, CHARINDEX( '_',T.[PATH])-1) + '.trc'
ELSE T.[PATH]
END, T.max_files) I
LEFT Outer Join sys.server_principals S
ON CONVERT(VARBINARY(MAX), I.loginsid) = S.sid
LEFT Outer Join ConnectInfo EC
ON EC.SPID = I.SPID
And EC.loginname = I.LoginName
WHERE T.id = 1
And I.LoginSid IS not null
GROUP BY I.NTUserName,I.loginname,I.SessionLoginName,I.databasename,EC.ClientHost,I.HostName,I.ApplicationName
,I.StartTime,S.principal_id,S.sid,S.type_desc,S.name,EC.EventTime
HAVING DATEDIFF(dd, MAX(I.StartTime), GETDATE()) <= 30
ORDER BY databasename, loginname, I.StartTime

The last such report that I wish to share related to this topic is to find current activity.  Since the original idea was to combine the trace with the DMV, I decided that I needed to at least look at the DMV for a relevant query.  These DMV’s provide current activity and need to be combined to provide a quick snapshot of the activity that is occuring on the server at a given moment.  One quick snapshot can tell me who is logged in, from what IP Address, the application, read and write activity, and what the SQL is that is being executed.

SELECT ec.session_id, es.login_name,ec.client_net_address,es.program_name,es.login_time
,es.last_request_start_time,es.memory_usage,es.total_elapsed_time,st.TEXT
,ec.num_reads,ec.num_writes,es.status
FROM sys.dm_exec_connections ec
INNER Join sys.dm_exec_sessions es
ON ec.session_id = es.session_id
Cross Apply sys.dm_exec_sql_text(ec.most_recent_sql_handle) st

There are several queries out there similar to this last one.  The idea is to capture a quick glimpse based on the DMVs which in essence are a report of a subset of server relevant information.

Conclusion

When it is necessary to provide reports on activity occurring on the server, it pays to do a little prep work.  Be Prepared.  It is not an easy task to be able to go back in time and report on data that isn’t captured.  The little prep work that one may need to do is well worth the effort in the end.

Rate

You rated this post out of 5. Change rating

Share

Share

Rate

You rated this post out of 5. Change rating