All of a sudden the the web application for the database my nonprofit uses stopped functioning as it should. Basically I can't save any new entry. I can edit entries, but whenever I make new entry I get the error.
The app my organization uses is custom C# app. I was digging through the logs and I isolated the problem to a table which tracks user sessions.
NHibernate.Exceptions.GenericADOException: could not execute batch command.[SQL: SQL not available] ---> System.Data.SqlClient.SqlException: Violation of PRIMARY KEY constraint 'PK__tUserSes__3214EC07F91B0D0B'. Cannot insert duplicate key in object 'SiteUser.tUserSession'. The duplicate key value is (7062).
That table has more than 300000 entries and the Id is clearly wrong, it's not the Id it should be. The more back I go in the logs the lower the Id number. It's like at some the Id counter was rested.
Whenever I try to add a new entry I get "System error occurred during request processing. Please contact the system administrator." which in logs looks like Cannot insert duplicate key in object 'SiteUser.tUserSession'. The duplicate key value is (7062).
I tracked down the logs to the point where the error appeared for the first time. It was actually at the beginning of the log file for the day 20180507.log
2018-05-07 00:24:29,990 WARN NHibernate.Util.ADOExceptionReporter - System.Data.SqlClient.SqlException (0x80131904): Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction)
at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
at System.Data.SqlClient.TdsParser.TdsExecuteTransactionManagerRequest(Byte[] buffer, TransactionManagerRequestType request, String transactionName, TransactionManagerIsolationLevel isoLevel, Int32 timeout, SqlInternalTransaction transaction, TdsParserStateObject stateObj, Boolean isDelegateControlRequest)
at System.Data.SqlClient.SqlInternalConnectionTds.ExecuteTransactionYukon(TransactionRequest transactionRequest, String transactionName, IsolationLevel iso, SqlInternalTransaction internalTransaction, Boolean isDelegateControlRequest)
at System.Data.SqlClient.SqlInternalTransaction.Commit()
at System.Data.SqlClient.SqlTransaction.Commit()
at NHibernate.Transaction.AdoNetTransactionFactory.ExecuteWorkInIsolation(ISessionImplementor session, IIsolatedWork work, Boolean transacted)ClientConnectionId:c6788280-f7cc-4c3a-9bf2-514f4df84fc9
Error Number:-2,State:0,Class:11
2018-05-07 00:24:30,006 ERROR NHibernate.Util.ADOExceptionReporter - Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
2018-05-07 00:24:30,006 WARN NHibernate.Util.ADOExceptionReporter - System.ComponentModel.Win32Exception (0x80004005): The wait operation timed out
2018-05-07 00:24:30,006 ERROR NHibernate.Util.ADOExceptionReporter - The wait operation timed out
2018-05-07 00:24:30,006 ERROR NHibernate.Base.Transaction.With - Transaction failed.
NHibernate.Exceptions.GenericADOException: error performing isolated work[SQL: SQL not available] ---> System.Data.SqlClient.SqlException: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception: The wait operation timed out
--- End of inner exception stack trace ---
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction)
1 wrapCloseInAction) at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose) at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady) at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj) at System.Data.SqlClient.TdsParser.TdsExecuteTransactionManagerRequest(Byte[] buffer, TransactionManagerRequestType request, String transactionName, TransactionManagerIsolationLevel isoLevel, Int32 timeout, SqlInternalTransaction transaction, TdsParserStateObject stateObj, Boolean isDelegateControlRequest) at System.Data.SqlClient.SqlInternalConnectionTds.ExecuteTransactionYukon(TransactionRequest transactionRequest, String transactionName, IsolationLevel iso, SqlInternalTransaction internalTransaction, Boolean isDelegateControlRequest) at System.Data.SqlClient.SqlInternalTransaction.Commit() at System.Data.SqlClient.SqlTransaction.Commit() at NHibernate.Transaction.AdoNetTransactionFactory.ExecuteWorkInIsolation(ISessionImplementor session, IIsolatedWork work, Boolean transacted) --- End of inner exception stack trace --- at NHibernate.Transaction.AdoNetTransactionFactory.ExecuteWorkInIsolation(ISessionImplementor session, IIsolatedWork work, Boolean transacted) at NHibernate.Transaction.AdoNetWithDistributedTransactionFactory.ExecuteWorkInIsolation(ISessionImplementor session, IIsolatedWork work, Boolean transacted) at NHibernate.Engine.TransactionHelper.DoWorkInNewTransaction(ISessionImplementor session) at NHibernate.Id.MultipleHiLoPerTableGenerator.Generate(ISessionImplementor session, Object obj) at NHibernate.Event.Default.AbstractSaveEventListener.SaveWithGeneratedId(Object entity, String entityName, Object anything, IEventSource source, Boolean requiresImmediateIdAccess) at NHibernate.Event.Default.DefaultSaveOrUpdateEventListener.SaveWithGeneratedOrRequestedId(SaveOrUpdateEvent event) at NHibernate.Event.Default.DefaultSaveOrUpdateEventListener.EntityIsTransient(SaveOrUpdateEvent event) at NHibernate.Event.Default.DefaultSaveOrUpdateEventListener.OnSaveOrUpdate(SaveOrUpdateEvent event) at NHibernate.Impl.SessionImpl.FireSaveOrUpdate(SaveOrUpdateEvent event) at NHibernate.Impl.SessionImpl.SaveOrUpdate(Object obj) at Quiddita.Business.Statistics.Services.StatisticsBusinessService.<>c__DisplayClass1.b__0() in d:\Projects\CAT – Site Database\Source\Quiddita.Business.Statistics\Services\StatisticsBusinessService.cs:line 71 at NHibernate.Base.Transaction.With.Transaction(IsolationLevel level, Action transactional) in d:\Projects\CAT – Site Database\Source\NHibernate.Base\Transaction\With.Transaction.cs:line 54 at Quiddita.Business.Statistics.Services.StatisticsBusinessService.CreateNewUserSession(Nullable
at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose)
at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
at System.Data.SqlClient.TdsParser.TdsExecuteTransactionManagerRequest(Byte[] buffer, TransactionManagerRequestType request, String transactionName, TransactionManagerIsolationLevel isoLevel, Int32 timeout, SqlInternalTransaction transaction, TdsParserStateObject stateObj, Boolean isDelegateControlRequest)
at System.Data.SqlClient.SqlInternalConnectionTds.ExecuteTransactionYukon(TransactionRequest transactionRequest, String transactionName, IsolationLevel iso, SqlInternalTransaction internalTransaction, Boolean isDelegateControlRequest)
at System.Data.SqlClient.SqlInternalTransaction.Commit()
at System.Data.SqlClient.SqlTransaction.Commit()
at NHibernate.Transaction.AdoNetTransactionFactory.ExecuteWorkInIsolation(ISessionImplementor session, IIsolatedWork work, Boolean transacted)
--- End of inner exception stack trace ---
at NHibernate.Transaction.AdoNetTransactionFactory.ExecuteWorkInIsolation(ISessionImplementor session, IIsolatedWork work, Boolean transacted) at NHibernate.Transaction.AdoNetWithDistributedTransactionFactory.ExecuteWorkInIsolation(ISessionImplementor session, IIsolatedWork work, Boolean transacted) at NHibernate.Engine.TransactionHelper.DoWorkInNewTransaction(ISessionImplementor session) at NHibernate.Id.MultipleHiLoPerTableGenerator.Generate(ISessionImplementor session, Object obj) at NHibernate.Event.Default.AbstractSaveEventListener.SaveWithGeneratedId(Object entity, String entityName, Object anything, IEventSource source, Boolean requiresImmediateIdAccess) at NHibernate.Event.Default.DefaultSaveOrUpdateEventListener.SaveWithGeneratedOrRequestedId(SaveOrUpdateEvent event) at NHibernate.Event.Default.DefaultSaveOrUpdateEventListener.EntityIsTransient(SaveOrUpdateEvent event) at NHibernate.Event.Default.DefaultSaveOrUpdateEventListener.OnSaveOrUpdate(SaveOrUpdateEvent event) at NHibernate.Impl.SessionImpl.FireSaveOrUpdate(SaveOrUpdateEvent event) at NHibernate.Impl.SessionImpl.SaveOrUpdate(Object obj) at Quiddita.Business.Statistics.Services.StatisticsBusinessService.<>c__DisplayClass1.<CreateNewUserSession>b__0() in d:\Projects\CAT – Site Database\Source\Quiddita.Business.Statistics\Services\StatisticsBusinessService.cs:line 71 at NHibernate.Base.Transaction.With.Transaction(IsolationLevel level, Action transactional) in d:\Projects\CAT – Site Database\Source\NHibernate.Base\Transaction\With.Transaction.cs:line 39 2018-05-07 00:24:30,037 ERROR Quiddita.Aspects.Statistics.MethodBoundaryAspects.NewSessionAspectAttribute - NewSessionAspectAttribute.OnSuccess failed to execute. NHibernate.Exceptions.GenericADOException: error performing isolated work[SQL: SQL not available] ---> System.Data.SqlClient.SqlException: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception: The wait operation timed out --- End of inner exception stack trace --- at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action1 userId, String IPAddress) in d:\Projects\CAT – Site Database\Source\Quiddita.Business.Statistics\Services\StatisticsBusinessService.cs:line 74 at Quiddita.Aspects.Statistics.MethodBoundaryAspects.NewSessionAspectAttribute.OnSuccess(MethodExecutionArgs args) in d:\Projects\CAT – Site Database\Source\Quiddita.Aspects.Statistics\MethodBoundaryAspects\NewSessionAspectAttribute.cs:line 68 2018-05-07 00:24:31,056 WARN NHibernate.Util.ADOExceptionReporter - System.Data.SqlClient.SqlException (0x80131904): Violation of PRIMARY KEY constraint 'PK__tUserSes__3214EC07F91B0D0B'. Cannot insert duplicate key in object 'SiteUser.tUserSession'. The duplicate key value is (1). The statement has been terminated. at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action
1 wrapCloseInAction) at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose) at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady) at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString) at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, SqlDataReader ds) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource1 completion, Int32 timeout, Task& task, Boolean asyncWrite) at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource
1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean asyncWrite) at System.Data.SqlClient.SqlCommand.ExecuteNonQuery() at System.Data.SqlClient.SqlCommandSet.ExecuteNonQuery() at NHibernate.AdoNet.SqlClientBatchingBatcher.DoExecuteBatch(IDbCommand ps) ClientConnectionId:a7af4119-1d67-4f69-ae91-fc556c97768f Error Number:2627,State:1,Class:14 2018-05-07 00:24:31,068 ERROR NHibernate.Util.ADOExceptionReporter - Violation of PRIMARY KEY constraint 'PK__tUserSes__3214EC07F91B0D0B'. Cannot insert duplicate key in object 'SiteUser.tUserSession'. The duplicate key value is (1). The statement has been terminated. 2018-05-07 00:24:31,068 ERROR NHibernate.Event.Default.AbstractFlushingEventListener - Could not synchronize database state with session NHibernate.Exceptions.GenericADOException: could not execute batch command.[SQL: SQL not available] ---> System.Data.SqlClient.SqlException: Violation of PRIMARY KEY constraint 'PK__tUserSes__3214EC07F91B0D0B'. Cannot insert duplicate key in object 'SiteUser.tUserSession'. The duplicate key value is (1). The statement has been terminated. at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction) at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose) at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady) at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString) at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, SqlDataReader ds) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource
1 completion, Int32 timeout, Task& task, Boolean asyncWrite) at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1 completion, String methodName, Boolean sendToPipe, Int32 timeout, Boolean asyncWrite) at System.Data.SqlClient.SqlCommand.ExecuteNonQuery() at System.Data.SqlClient.SqlCommandSet.ExecuteNonQuery() at NHibernate.AdoNet.SqlClientBatchingBatcher.DoExecuteBatch(IDbCommand ps) --- End of inner exception stack trace --- at NHibernate.AdoNet.SqlClientBatchingBatcher.DoExecuteBatch(IDbCommand ps) at NHibernate.AdoNet.AbstractBatcher.ExecuteBatchWithTiming(IDbCommand ps) at NHibernate.AdoNet.AbstractBatcher.ExecuteBatch() at NHibernate.Engine.ActionQueue.ExecuteActions() at NHibernate.Event.Default.AbstractFlushingEventListener.PerformExecutions(IEventSource session) 2018-05-07 00:24:31,068 ERROR NHibernate.Base.Transaction.With - Transaction failed.
An this is part of the StatisticsBusinessService.cs:line 74
/// <summary>
/// Creates new <c>UserSession</c> and saves the object to database.
/// </summary>
/// <param name="userId">The database id of the<see cref="User"/> associated with the Session. If <c>null</c> then the anonymous user is in question.</param>
/// <param name="IPAddress">The IPAddress of the client machine the page was accessed from.</param>
/// <returns>The newly created <c>UserSession</c> object.</returns>
public UserSession CreateNewUserSession(long? userId, string IPAddress)
{
UserSession userSession = null;
With.Transaction(() =>
{
userSession = InitializeUserSession();
if (userId.HasValue)
userSession.User = _securityService.LoadUser(userId.Value, null);
userSession.IPAddress = IPAddress;
UnitOfWork.CurrentSession.SaveOrUpdate(userSession);
});
return userSession;
}
I discovered that in the hours prior to the problem appearing we were getting a bunch of brute force password guesses. Each of those was logged in a session table. The logins kept coming but we implemented a firewall to allow only a set of IP to login. So I think we haven't been breached.
Prior to the problem the Windows server wasn't accessed in weeks. The files haven't been changed, and the database hasn't been changed. The windows hasn't been updated. Basically nothing on the system changed, but the id counter was somehow reset. I checked the database, the id columns weren't set to identity (false), so I guess the auto-increment has been implemented in the app, rather than at the database level.
I have 0 experience with C#, SQL Server and the entire Windows ecosystem. I am at a complete loss of what is going on.
We use Windows Server 2012r2, SQL Server 2014 Express, IIS 8
Any clue will be much appreciated.
What a stack trace!
If I've understood correctly your autonumber seed just got reset. Make a backup and try this:
SELECT MAX(tUserSession) FROM SiteUser
You'll got a number, let say 123456 then reseed your autonumber with the same value:
DBCC CHECKIDENT (SiteUser, RESEED, 123456)
User contributions licensed under CC BY-SA 3.0