IP and Default Trace…T-SQL Tuesday #005

Comments: 9 Comments
Published on: April 6, 2010

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 gets the IP Address from the ClientHost Field of EventData() which is 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.

Edit:  Corrected 1 detail and fixed some formatting.

9 Comments - Leave a comment
  1. [...] This post was mentioned on Twitter by Jason Brimhall. Jason Brimhall said: New post: IP and Default Trace…T-SQL Tuesday #005 (http://bit.ly/9ZYoMT) [...]

  2. [...] This post was mentioned on Twitter by Jason Brimhall, Jason Brimhall. Jason Brimhall said: New post: IP and Default Trace…T-SQL Tuesday #005 (http://bit.ly/9ZYoMT) [...]

  3. Raj says:

    Hi Jason,

    Good post. I have a doubt. For correlating the audit data and trace data, I expected a join condition between
    EC.EventTime and I.StartTime. I may be missing something here. Please explain how a row captured using logon trigger correctly matches trace files entries.

    But again,useful post.

    Regards,
    Raj

  4. Jason Brimhall says:

    Raj,
    Good assertion. Yes an additional join condition would render it more accurate. My only concern is whether or not the time stamps would match between the two. In which case one would need to alter the join condition on time to be less specific in the time match (i.e. not match seconds).

    Thanks for your input.

  5. Raj says:

    Hi Jason,

    Thanks for the reply. Yes time level match should be perfect when combined with spid and login name conditions. A great write up and thanks again for the technique.

    Regards,
    Raj

  6. Very interesting idea!!

    I can check this out for myself, but do you know if you can tell the server name the person used for connecting? We use virtual names for our replica servers via load balancing, and occassionally we get emails from users that decided to use the server name and then we take one of the servers offline for maintenance and their ETL no longer works. So, I’m just wondering if a logon trigger could capture users that use the server name instead of the virtual name.

    • Jason Brimhall says:

      I would have to check that as well. I did not test for the use of virtual name versus server name.

  7. [...] it by now, I made a bone-headed mistake last week by submitting my entry one week early.  That entry was about trying to create a report that would join information between some DMVs and the Default [...]

  8. [...] hope you will find good use for it as well. Related Posts:IP and Default Trace…T-SQL Tuesday #005TSQL Challenge 63 – UpdateLast Time CheckDB was RunLast Known Good CheckDBPhysical Row [...]

Leave a comment

Your email address will not be published. Required fields are marked *

You may use these HTML tags and attributes: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <strike> <strong>






Calendar
April 2010
M T W T F S S
« Mar   May »
 1234
567891011
12131415161718
19202122232425
2627282930  
Content
SQLHelp

SQLHelp


Welcome , today is Friday, April 18, 2014