Event 5586 SQL Error 18452 Login failed for user 'Null'

[jremmc]

Researched this before posting; please note permissions look ok and SQL is in
mixed mode.

Project Server 2007 with SP1 and Infrastructure Update. Installed MOPS a few
months ago but it is not in use yet. WSS 3.0 team sites in use for over a
year, but not heavily. One front-end W2K3 R2 SP1 server, one back-end W2K3
SP1 SQL 2000 SP4 server. Getting Event 5586 showing SQL error 18452 Login
failed for user 'null', with increasing frequency beginning January 6th. On
January 5th I installed the following updates on both servers: 957097,
958215, 955839, 955069, 954600, 960714, 952069, 956802.

I verified: SQL Authentication is mixed mode; has always been. All services
are running as domain accounts and these accounts are administrators on both
the SQL and MOPS server. Except the SharePoint Services Administration
service is Local System; I assume SharePoint install did that. SQL databases
permissions for the domain service accounts look ok (is there a KB article
that shows how to verify step-by-step?) Also, the MOPS server account has
WSS_Content_Application_Pool role in SharePoint_Config and
SharePoint_AdminContent.. databases; that covers the Administration Service,
yes? No one has modified any settings for the SharePoint logins or databases.
Account passwords haven't changed and are set to not expire, Services.msc
applet shows proper accounts being used for the services. No other errors in
Event Log. SharePoint Timer jobs succeeding. No users reporting issues with
WSS. WSS BPA does not report errors. "Check services in farm" reports no
errors. Event does not correlate with backup times or the nightly scheduled
task running stsadm to do individual site backups with locks.

By increasing frequency I mean: I reviewed App Log for exact Event/Cause and
found same reported as so: Pre-MOPS: exactly once on 2 days in 2007 6 months
apart, then once again 9 months later. On MOPS install day 10/10/08, 3 hours
later, 7 times within half-hour period. Since then: 12/15/08 3x w/in a
minute; 1/6/09 3x each at 1am, 1:30am, 10:14pm, 10:54pm; 1/9/08 once at
9:15pm then 3x at 10:20-22PM; 1/10/09 4X at 1:50am; 1/12 2x at 9:42pm and 3x
at 10:18-19pm; 1/13/09 2x at 10:02pm and 3x at 10:38pm; 1/14/09 9x at 8am.

Below is some of the data from trace log (server name changed). If issue is
a particular SharePoint service account permissions issue, what/where exactly
in SQL Enterprise Manager should I see checked off for what service account?
If not that, how can I determine who user 'null' is?

Thanks,
jremmc


System.Data.SqlClient.SqlException: Login failed for user '(null)'. Reason:
Not associated with a trusted SQL Server connection. at
System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception,
Boolean breakConnection) at
System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject
stateObj) at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior,
SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet
bulkCopyHandler, TdsParserStateObject stateObj) at
System.Data.SqlClient.SqlInternalConnectionTds.CompleteLogin(Boolean
enlistOK) at
System.Data.SqlClient.SqlInternalConnectionTds.AttemptOneLogin(ServerInfo
serverInfo, String newPassword, Boolean ignoreSniOpenTimeout, Int64
timerExpire, SqlConnection owningObject) ...
.... at System.Data.SqlClient.SqlInternalConnectionTds.LoginNoFailover(String
host, String newPassword, Boolean redirectedUserInstance, SqlConnection
owningObject, SqlConnectionString connectionOptions, Int64 timerStart) at
System.Data.SqlClient.SqlInternalConnectionTds.OpenLoginEnlist(SqlConnection
owningObject, SqlConnectionString connectionOptions, String newPassword,
Boolean redirectedUserInstance) at
System.Data.SqlClient.SqlInternalConnectionTds..ctor(DbConnectionPoolIdentity
identity, SqlConnectionString connectionOptions, Object providerInfo, String
newPassword, SqlConnection owningObject, Boolean redirectedUserInstance)
at
System.Data.SqlClient.SqlConnectionFactory.CreateConnection(DbConnectionOptions options, Object poolGroupProviderInfo, DbConnectionPool pool, DbConnecti...
....on owningConnection) at
System.Data.ProviderBase.DbConnectionFactory.CreatePooledConnection(DbConnection
owningConnection, DbConnectionPool pool, DbConnectionOptions options) at
System.Data.ProviderBase.DbConnectionPool.CreateObject(DbConnection
owningObject) at
System.Data.ProviderBase.DbConnectionPool.UserCreateRequest(DbConnection
owningObject) at
System.Data.ProviderBase.DbConnectionPool.GetConnection(DbConnection
owningObject) at
System.Data.ProviderBase.DbConnectionFactory.GetConnection(DbConnection
owningConnection) at
System.Data.ProviderBase.DbConnectionClosed.OpenConnection(DbConnection
outerConnection, DbConnectionFactory connectionFactory) at
System.Data.SqlClient.SqlConnection.Open() at
Microsoft.SharePoint.Utilities.SqlSession.OpenConnection()

SqlError: 'Login failed for user '(null)'. Reason: Not associated with a
trusted SQL Server connection.' Source: '.Net SqlClient Data Provider'
Number: 18452 State: 1 Class: 14 Procedure: '' LineNumber: 0 Server:
'SQLServer'

Unknown SQL Exception 18452 occured. Additional error information from SQL
Server is included below.

Login failed for user '(null)'. Reason: Not associated with a trusted SQL
Server connection.
at Microsoft.SharePoint.Utilities.SqlSession.ExecuteReader(SqlCommand
command, CommandBehavior behavior) at
Microsoft.SharePoint.Administration.SPConfigurationDatabase.FetchId(QualifiedObjectName
qName) at
Microsoft.SharePoint.Administration.SPConfigurationDatabase.GetObject(String
name, Guid parentId, Type type) at
Microsoft.SharePoint.Administration.SPConfigurationDatabase.get_Farm() at
Microsoft.SharePoint.Administration.SPConfigurationDatabase.SPFileSystemCacheWatcher.OnChanged(Object
source, FileSystemEventArgs e) at
System.IO.FileSystemWatcher.OnChanged(FileSystemEventArgs e) at
System.IO.FileSystemWatcher.NotifyFileSystemEventArgs(Int32 action, String
name) at System.IO.FileSystemWatcher.CompletionStatusChanged(UInt32
errorCode, UInt32 numBytes, Native...

....Overlapped* overlappedPointer) at
System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32
errorCode, UInt32 numBytes, NativeOverlapped* pOVERLAP)
ConnectionString: 'Data Source=SQLServer;Initial
Catalog=SharePoint_Config;Integrated Security=True;Enlist=False'
ConnectionState: Closed ConnectionTimeout: 15

 

[jremmc]

More information:

(1) KB 957097 (one of the updates applied) known issues involves NTLM
authentication requests and SQL Server. But concerns local authentication
requests; wouldn't the SharePointservice accounts and the server account be
remote authentication requests?

(2) I closely correlated our backup times of the MOPS and SQL servers
(Backup Exec 12.0) and the backup account's logons/logoffs to those servers
in respective Security logs. I found that the backup account (a domain
account) logged onto or off of the *MOPS* server in 90% of the instances when
Event 5585 occured. The event times did *not* correlate with backups of the
SQL server drives or databases (we use the SQL Backup Agent).

In 10% of the instances, I still cannot find a rhyme or reason for the 5586
Event, and anyway, I don't see how the backup account logging onto or off of
the MOPS server can cause a failed login to SQL.

Any one got any clue?

Thanks,
jremmc

 

[jremmc]

More info still, even though at this point I don't expect an answer...

I am also getting Event 6033 from LsaSrv on the SQL server -- "An anonymous
session connected from SQLServer has attempted to open an LSA policy handle
on this machine. The attempt was rejected with STATUS_ACCESS_DENIED to
prevent leaking security sensitive information to the anonymous caller."
Checking the Security log for logon/logoff info, I can see that Anonymous is
coming from the SharePoint server. And even though 6033 is logged only once a
day, the log times correlate with 5586 events.

jremmc