2

Being able to view details of who successfully logs into a database and which user's login failed via the error logs is a good thing. However I have a scenario that I need help with:

For some reason the success and failure details are logged multiple times and as such if I login to a SQL Server 2008 R2 instance this very minute, I see multiple "Login successful for user ..." messages.

Can anyone help to resolve this (without turning off the option to save login success/failure) as it is filling up the logs and pushing down relevant information. Example of a successful login for a user recorded multiple times in the same min, second

  • Failures are logged multiple times because user tried multiple times. I dont think it is an issue. Can you post a fragment of errorlog here to prove your point. Edit your question and paste it – Shanky Sep 15 '14 at 13:24
  • The post has been edited Shanky. This happens for both failures and success – daffyjeje Sep 15 '14 at 13:32
  • Thanks for the edit can you please make one more edit and expand time so that it can be visible in errorlog – Shanky Sep 15 '14 at 13:34
  • All happened the same time 12:38:00 – daffyjeje Sep 15 '14 at 13:36
  • Are these all same users or different. I have seen such messages in errorlog but not for same user – Shanky Sep 15 '14 at 13:46
7

I realize this doesn't answer the question "why does the log file have multiple entries for 'Login succeeded...'", however since you also seem to be concerned about the other log entries being "drowned-out" by these low-importance login messages, I thought I'd add the following as an answer.

Instead of using SQL Server Management Studio's built-in interface for looking at log files, you can use the following code that will allow you to ignore log messages you are not interested in. This allows you to concentrate on messages that may be more immediately relevant.

IF NOT EXISTS(
    SELECT s.name + '.' + t.name 
    FROM tempdb.sys.tables t 
        INNER JOIN tempdb.sys.schemas s ON t.schema_id = s.schema_id 
    WHERE s.name + '.' + t.name = 'dbo.ErrorLogAnalysis'
    )
BEGIN
    CREATE TABLE tempdb.dbo.ErrorLogAnalysis
    (
        LogDate DATETIME,
        ProcessInfo NVARCHAR(255),
        [Text] NVARCHAR(MAX)
    );
END

TRUNCATE TABLE tempdb.dbo.ErrorLogAnalysis;
EXEC sp_ReadErrorLog 0,1;
INSERT INTO tempdb.dbo.ErrorLogAnalysis
SELECT ela.*
FROM tempdb.dbo.ErrorLogAnalysis ela
WHERE ela.Text NOT LIKE 'Login succeeded%'
ORDER BY LogDate DESC;

It may be helpful to point out that client-side code is quite likely to use more than a single connection to SQL Server. This may in fact be the precise reason why more than a single entry is recorded in the SQL Server Error Log.

To prove this, I've written a very simple VB.Net command-line app that creates 5 connections to my local SQL Server instance. Once all five connections have been opened, the app executes a simple query against the server showing 5 session_id values that the app has open. It then closes all 5 connections, and exits.

This is the code:

Module Module1

    Sub Main()

        Dim sConnString As String =
            "SERVER=localhost;" & _
            "DATABASE=master;" & _
            "TRUSTED_CONNECTION=True;" & _
            "Application Name=MultiConnTest"
        Dim sqlC1 As New SqlClient.SqlConnection(sConnString)
        Dim sqlC2 As New SqlClient.SqlConnection(sConnString)
        Dim sqlC3 As New SqlClient.SqlConnection(sConnString)
        Dim sqlC4 As New SqlClient.SqlConnection(sConnString)
        Dim sqlC5 As New SqlClient.SqlConnection(sConnString)
        sqlC1.Open()
        sqlC2.Open()
        sqlC3.Open()
        sqlC4.Open()
        sqlC5.Open()
        Dim sqlCMD As New SqlClient.SqlCommand( _
            "SELECT session_id, login_name " & _
            "FROM sys.dm_exec_sessions des " & _
            "WHERE des.host_name = HOST_NAME " & _
            "   AND des.program_name = 'MultiConnTest';", sqlC1)
        Console.WriteLine("Testing multiple connections to SQL Server.")
        Console.WriteLine()
        Console.WriteLine("Sessions currently open on the server, with username")
        Dim sqlReader As SqlClient.SqlDataReader = sqlCMD.ExecuteReader
        Dim iSessionID As Int32
        Dim sUserName As String
        While sqlReader.Read
            iSessionID = sqlReader.GetValue(0)
            sUserName = sqlReader.GetValue(1)
            Console.WriteLine(iSessionID & vbTab & sUserName)
        End While
        sqlReader.Close()
        sqlCMD = Nothing
        sqlC1.Close()
        sqlC2.Close()
        sqlC3.Close()
        sqlC4.Close()
        sqlC5.Close()
        Console.WriteLine("Press any key to exit")
        Console.ReadKey()

    End Sub

End Module

The console output from running this against my machine is:

Testing multiple connections to SQL Server.

Sessions currently open on the server, with username
52      Max
53      Max
54      Max
55      Max
56      Max
Press any key to exit

The SQL Server Error Log, after enabling auditing of both successful and unsuccessful logins, shows:

LogDate                 ProcessInfo Text
2014-09-16 10:31:54.290 Logon       Login succeeded for user 'Max'. Connection made using Windows authentication. [CLIENT: <local machine>]
2014-09-16 10:31:54.290 Logon       Login succeeded for user 'Max'. Connection made using Windows authentication. [CLIENT: <local machine>]
2014-09-16 10:31:54.290 Logon       Login succeeded for user 'Max'. Connection made using Windows authentication. [CLIENT: <local machine>]
2014-09-16 10:31:54.290 Logon       Login succeeded for user 'Max'. Connection made using Windows authentication. [CLIENT: <local machine>]
2014-09-16 10:31:54.290 Logon       Login succeeded for user 'Max'. Connection made using Windows authentication. [CLIENT: <local machine>]

I think you can see from this a possible source of your error log entries is not some errant SQL Server behavior that can be "disabled", but is far more likely to be the desired result arising from the combination of auditing successful logins, and client applications that use multiple connections.

I would check the source code of whatever applications are running against your SQL Server to determine if they are in-fact using multiple connections.

If they are, I would use sp_readerrorlog to look at the error log. I might even go so far as to create a stored procedure to encapsulate the functionality of sp_readerrorlog to produce output in whatever format you desire.

  • 1
    But max question is why multiple entries at same time. – Shanky Sep 15 '14 at 14:21
  • Max workarounds are usually good until, you cant workaround a particular issue. I'll definitely keep your advice in mind. However i would still like to understand what changed and why a single login is being recorded multiple times – daffyjeje Sep 15 '14 at 14:35
  • I saw "filling up the logs and pushing down relevant information." and thought the likely reason you are posting this question is so you can actually see relevant log information. – Max Vernon Sep 15 '14 at 15:00
  • 5
    As I clearly show in my updated answer above, it is very likely that any well-written client-side application may well open multiple connections to SQL Server, exhibiting the precise behavior you are seeing. – Max Vernon Sep 16 '14 at 15:54
  • 1
    Thanks Max for your response. Your explanation certainly helped with a new perspective to look at this. – daffyjeje Sep 17 '14 at 7:06
-1
CREATE TABLE #ErrorLogAnalysis
(
  LogDate DATETIME,
  ProcessInfo NVARCHAR(255),
  [Text] NVARCHAR(MAX)
 );
INSERT INTO #ErrorLogAnalysis
EXEC sp_ReadErrorLog 0,1
SELECT *
FROM #ErrorLogAnalysis
WHERE [Text] NOT LIKE 'Login Succeeded%'
ORDER BY LogDate;
DROP TABLE #ErrorLogAnalysis

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.