Build/Test Issues

Using EnableRdi(false) attribute results in NullReferenceException from LogStateMachineCompletion

Started by Magnus Lidbom on 4,481 views

It seems to not be entirely deterministic. The first time I tried to use the attribute it happened as soon as I applied it.
Later, in other code, I thought it was working, but then when I restarted the NCrunch engine the test started failing with the below exception.
For yet another test it seems to just work so far.


EXCEPTION: System.NullReferenceException: Object reference not set to an instance of an object.
   at nCrunch.TestRuntime.DotNetCore.RuntimeDataInspection.RdiEventListener.NCrunchLogStateMachineCompletion(Object stateMachineInstance, Int32 componentMappingId, UInt32 outerScopeTransientId, UInt32 outerScopeFrameIndex, Int64 frameStartInLog)
   at Composable.SystemCE.ThreadingCE.SyncOrAsyncCE.Run(SyncOrAsync syncOrAsync, Action synchronous, Func`1 asynchronous) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\ThreadingCE\SyncOrAsync.cs:line 39
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
   at Composable.SystemCE.ThreadingCE.SyncOrAsyncCE.Run(SyncOrAsync syncOrAsync, Action synchronous, Func`1 asynchronous)
   at Composable.Persistence.PgSql.IComposableNpgsqlConnection.ComposableNpgsqlConnection.Composable.Persistence.Common.AdoCE.IPoolableConnection.OpenAsyncFlex(SyncOrAsync syncOrAsync) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\PgSql\ComposableNpgsqlConnection.cs:line 24
   at Composable.SystemCE.ThreadingCE.SyncOrAsyncCE.SyncResult(Task this) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\ThreadingCE\SyncOrAsync.cs:line 52
   at Composable.SystemCE.ThreadingCE.SyncOrAsyncCE.<>c__DisplayClass1_0.<AsSync>b__0() in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\ThreadingCE\SyncOrAsync.cs:line 20
   at Composable.SystemCE.DiagnosticsCE.StopwatchCE.TimeExecution(Stopwatch this, Action action) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\DiagnosticsCE\StopwatchCE.cs:line 28
   at Composable.SystemCE.DiagnosticsCE.StopwatchCE.TimeExecution(Action action) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\DiagnosticsCE\StopwatchCE.cs:line 20
   at Composable.SystemCE.DiagnosticsCE.StopwatchCE.TimeExecutionFlexAsync(SyncOrAsync syncOrAsync, Func`2 syncOrAsyncAction) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\DiagnosticsCE\StopwatchCE.cs:line 63
   at Composable.SystemCE.DiagnosticsCE.TimingsStatisticsCollector.TimeAsyncFlex(SyncOrAsync syncOrAsync, Func`2 syncOrAsyncFunc) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\DiagnosticsCE\TimingsStatisticsCollector.cs:line 81
   at Composable.Persistence.Common.AdoCE.DbConnectionManager`2.DefaultDbConnectionManager.OpenConnectionAsyncFlex(SyncOrAsync syncOrAsync) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\Common\AdoCE\DbConnectionPool.Pools.cs:line 61
   at Composable.Persistence.Common.AdoCE.DbConnectionManager`2.DefaultDbConnectionManager.UseConnectionAsyncFlex[TResult](SyncOrAsync syncOrAsync, Func`2 func) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\Common\AdoCE\DbConnectionPool.Pools.cs:line 69
   at Composable.Persistence.Common.AdoCE.DbConnectionManager`2.TransactionAffinityDbConnectionManager.UseConnectionAsyncFlex[TResult](SyncOrAsync syncOrAsync, Func`2 func) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\Common\AdoCE\DbConnectionPool.Pools.cs:line 87
   at Composable.SystemCE.ThreadingCE.SyncOrAsyncCE.SyncResult[TResult](Task`1 this) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\ThreadingCE\SyncOrAsync.cs:line 45
   at Composable.Persistence.Common.AdoCE.IDbConnectionPool`2.UseConnection[TResult](Func`2 func) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\Common\AdoCE\IDbConnectionPool.cs:line 18
   at Composable.Persistence.Common.AdoCE.IDbConnectionPool`2.UseCommand[TResult](Func`2 action)
   at Composable.Persistence.PgSql.Testing.Databases.PgSqlDatabasePool.ResetDatabase(Database db) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\PgSql\Testing\Databases\PgSqlDatabasePool.cs:line 64
   at Composable.Testing.Databases.DatabasePool.<>c__DisplayClass12_1.<ConnectionStringFor>b__3() in C:\Dev\Composable\src\framework\Composable.CQRS\Testing\Databases\DatabasePool.cs:line 84
   at Composable.SystemCE.TransactionsCE.TransactionScopeCe.Execute(Action action, TransactionScopeOption option, IsolationLevel isolationLevel) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\TransactionsCE\TransactionScopeCE.cs:line 28
   at Composable.SystemCE.TransactionsCE.TransactionScopeCe.SuppressAmbient(Action action) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\TransactionsCE\TransactionScopeCE.cs:line 13
   at Composable.Testing.Databases.DatabasePool.<>c__DisplayClass12_0.<ConnectionStringFor>b__0() in C:\Dev\Composable\src\framework\Composable.CQRS\Testing\Databases\DatabasePool.cs:line 84

Edited

Hi, thanks for sharing this issue.

My first thought here is whether this might be due to overlapping threads from other tests that have RDI enabled. Can you reproduce the issue at all by running the test in isolation?
Remco wrote:My first thought here is whether this might be due to overlapping threads from other tests that have RDI enabled. Can you reproduce the issue at all by running the test in isolation?


That test no longer has the attribute. I need to get work done :)
But with the test that just started failing with the attribute applied, yes I can.
It crashes every time when I run just that test alone from the test runner. But on the topic of threads, this test does run multiple threads internally.
Here is the complete output from the test:



NCrunch: This test was executed on server '(local)'

INFO:Composable.Testing.Databases.DatabasePool: 00:39:45.621 Reserved pool database: Composable_DatabasePool_0003

############################################# ERROR in : Composable.Testing.Databases.DatabasePool #############################################
MESSAGE:  
EXCEPTION: System.NullReferenceException: Object reference not set to an instance of an object.
   at nCrunch.TestRuntime.DotNetCore.RuntimeDataInspection.MemoryMappedLog.LogStateMachineCompletion(Object stateMachineInstance, Int32 componentMappingId, UInt32 outerScopeTransientId, UInt32 outerScopeFrameIndex, Int64 frameStartInLog)
   at nCrunch.TestRuntime.DotNetCore.RuntimeDataInspection.RdiEventListener.NCrunchLogStateMachineCompletion(Object stateMachineInstance, Int32 componentMappingId, UInt32 outerScopeTransientId, UInt32 outerScopeFrameIndex, Int64 frameStartInLog)
   at Composable.SystemCE.ThreadingCE.SyncOrAsyncCE.Run(SyncOrAsync syncOrAsync, Action synchronous, Func`1 asynchronous) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\ThreadingCE\SyncOrAsync.cs:line 39
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
   at Composable.SystemCE.ThreadingCE.SyncOrAsyncCE.Run(SyncOrAsync syncOrAsync, Action synchronous, Func`1 asynchronous)
   at Composable.Persistence.MsSql.IComposableMsSqlConnection.ComposableMsSqlConnection.Composable.Persistence.Common.AdoCE.IPoolableConnection.OpenAsyncFlex(SyncOrAsync syncOrAsync) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\MsSql\ComposableMsSqlConnection.cs:line 21
   at Composable.Persistence.Common.AdoCE.DbConnectionManager`2.DefaultDbConnectionManager.OpenConnectionAsyncFlex(SyncOrAsync syncOrAsync) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\Common\AdoCE\DbConnectionPool.Pools.cs:line 53
   at Composable.Persistence.Common.AdoCE.DbConnectionManager`2.DefaultDbConnectionManager.UseConnectionAsyncFlex[TResult](SyncOrAsync syncOrAsync, Func`2 func) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\Common\AdoCE\DbConnectionPool.Pools.cs:line 69
   at Composable.SystemCE.ThreadingCE.SyncOrAsyncCE.SyncResult[TResult](Task`1 this) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\ThreadingCE\SyncOrAsync.cs:line 45
   at Composable.Persistence.Common.AdoCE.IDbConnectionPool`2.UseConnection(Action`1 action) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\Common\AdoCE\IDbConnectionPool.cs:line 21
   at Composable.Persistence.MsSql.Testing.Databases.MsSqlDatabasePool.ResetDatabase(Database db) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\MsSql\Testing\Databases\MsSqlDatabasePool.cs:line 52
   at Composable.Testing.Databases.DatabasePool.<>c__DisplayClass12_1.<ConnectionStringFor>b__3() in C:\Dev\Composable\src\framework\Composable.CQRS\Testing\Databases\DatabasePool.cs:line 84
   at Composable.SystemCE.TransactionsCE.TransactionScopeCe.Execute(Action action, TransactionScopeOption option, IsolationLevel isolationLevel) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\TransactionsCE\TransactionScopeCE.cs:line 28
   at Composable.SystemCE.TransactionsCE.TransactionScopeCe.SuppressAmbient(Action action) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\TransactionsCE\TransactionScopeCE.cs:line 13
   at Composable.Testing.Databases.DatabasePool.<>c__DisplayClass12_0.<ConnectionStringFor>b__0() in C:\Dev\Composable\src\framework\Composable.CQRS\Testing\Databases\DatabasePool.cs:line 84


############################################# SERIALIZED EXCEPTION #############################################
{
  "$type": "System.NullReferenceException, System.Private.CoreLib",
  "Message": "Object reference not set to an instance of an object.",
  "Data": {
    "$type": "System.Collections.ListDictionaryInternal, System.Private.CoreLib"
  },
  "InnerException": null,
  "HelpLink": null,
  "Source": "nCrunch.TestRuntime.DotNetCore",
  "HResult": -2147467261
}

############################################# END ERROR #############################################

System.NullReferenceException : Object reference not set to an instance of an object.
   at nCrunch.TestRuntime.DotNetCore.RuntimeDataInspection.MemoryMappedLog.LogStateMachineCompletion(Object stateMachineInstance, Int32 componentMappingId, UInt32 outerScopeTransientId, UInt32 outerScopeFrameIndex, Int64 frameStartInLog)
   at nCrunch.TestRuntime.DotNetCore.RuntimeDataInspection.RdiEventListener.NCrunchLogStateMachineCompletion(Object stateMachineInstance, Int32 componentMappingId, UInt32 outerScopeTransientId, UInt32 outerScopeFrameIndex, Int64 frameStartInLog)
   at Composable.SystemCE.ThreadingCE.SyncOrAsyncCE.Run(SyncOrAsync syncOrAsync, Action synchronous, Func`1 asynchronous) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\ThreadingCE\SyncOrAsync.cs:line 39
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine)
   at Composable.SystemCE.ThreadingCE.SyncOrAsyncCE.Run(SyncOrAsync syncOrAsync, Action synchronous, Func`1 asynchronous)
   at Composable.Persistence.MsSql.IComposableMsSqlConnection.ComposableMsSqlConnection.Composable.Persistence.Common.AdoCE.IPoolableConnection.OpenAsyncFlex(SyncOrAsync syncOrAsync) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\MsSql\ComposableMsSqlConnection.cs:line 21
   at Composable.SystemCE.ThreadingCE.SyncOrAsyncCE.SyncResult(Task this) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\ThreadingCE\SyncOrAsync.cs:line 52
   at Composable.SystemCE.ThreadingCE.SyncOrAsyncCE.<>c__DisplayClass1_0.<AsSync>b__0() in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\ThreadingCE\SyncOrAsync.cs:line 20
   at Composable.SystemCE.DiagnosticsCE.StopwatchCE.TimeExecution(Stopwatch this, Action action) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\DiagnosticsCE\StopwatchCE.cs:line 28
   at Composable.SystemCE.DiagnosticsCE.StopwatchCE.TimeExecution(Action action) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\DiagnosticsCE\StopwatchCE.cs:line 20
   at Composable.SystemCE.DiagnosticsCE.StopwatchCE.TimeExecutionFlexAsync(SyncOrAsync syncOrAsync, Func`2 syncOrAsyncAction) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\DiagnosticsCE\StopwatchCE.cs:line 63
   at Composable.SystemCE.DiagnosticsCE.TimingsStatisticsCollector.TimeAsyncFlex(SyncOrAsync syncOrAsync, Func`2 syncOrAsyncFunc) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\DiagnosticsCE\TimingsStatisticsCollector.cs:line 81
   at Composable.Persistence.Common.AdoCE.DbConnectionManager`2.DefaultDbConnectionManager.OpenConnectionAsyncFlex(SyncOrAsync syncOrAsync) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\Common\AdoCE\DbConnectionPool.Pools.cs:line 61
   at Composable.Persistence.Common.AdoCE.DbConnectionManager`2.DefaultDbConnectionManager.UseConnectionAsyncFlex[TResult](SyncOrAsync syncOrAsync, Func`2 func) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\Common\AdoCE\DbConnectionPool.Pools.cs:line 69
   at Composable.SystemCE.ThreadingCE.SyncOrAsyncCE.SyncResult[TResult](Task`1 this) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\ThreadingCE\SyncOrAsync.cs:line 45
   at Composable.Persistence.Common.AdoCE.IDbConnectionPool`2.UseConnection[TResult](Func`2 func) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\Common\AdoCE\IDbConnectionPool.cs:line 18
   at Composable.Persistence.Common.AdoCE.IDbConnectionPool`2.ExecuteScalar(String commandText) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\Common\AdoCE\IDbConnectionPool.cs:line 35
   at Composable.Persistence.MsSql.Testing.Databases.MsSqlDatabasePool.EnsureDatabaseExistsAndIsEmpty(Database db) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\MsSql\Testing\Databases\MsSqlDatabasePool.cs:line 30
   at Composable.Testing.Databases.DatabasePool.<>c__DisplayClass12_0.<ConnectionStringFor>b__0() in C:\Dev\Composable\src\framework\Composable.CQRS\Testing\Databases\DatabasePool.cs:line 89
   at Composable.SystemCE.ThreadingCE.ResourceAccess.MonitorCE.Update[T](Func`1 func) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\ThreadingCE\ResourceAccess\MonitorCE.Functional..cs:line 22
   at Composable.Testing.Databases.DatabasePool.ConnectionStringFor(String reservationName) in C:\Dev\Composable\src\framework\Composable.CQRS\Testing\Databases\DatabasePool.cs:line 47
   at Composable.Persistence.MsSql.DependencyInjection.MsSqlPersistenceLayerRegistrar.<>c__DisplayClass1_1.<RegisterMsSqlPersistenceLayer>b__8() in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\MsSql\DependencyInjection\MsSqlPersistenceLayerRegistrar.cs:line 33
   at Composable.Persistence.MsSql.SystemExtensions.IMsSqlConnectionPool.MsSqlConnectionPool.<>c__DisplayClass3_0.<.ctor>b__0() in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\MsSql\SystemExtensions\MsSqlConnectionPool.cs:line 25
   at Composable.SystemCE.OptimizedLazy`1.<get_Value>b__4_0() in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\OptimizedLazy.cs:line 18
   at Composable.SystemCE.ThreadingCE.ResourceAccess.MonitorCE.Update[T](Func`1 func) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\ThreadingCE\ResourceAccess\MonitorCE.Functional..cs:line 22
   at Composable.SystemCE.OptimizedLazy`1.get_Value() in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\OptimizedLazy.cs:line 18
   at Composable.Persistence.MsSql.SystemExtensions.IMsSqlConnectionPool.MsSqlConnectionPool.get_Pool() in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\MsSql\SystemExtensions\MsSqlConnectionPool.cs:line 18
   at Composable.Persistence.MsSql.SystemExtensions.IMsSqlConnectionPool.MsSqlConnectionPool.UseConnectionAsyncFlex[TResult](SyncOrAsync syncOrAsync, Func`2 func) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\MsSql\SystemExtensions\MsSqlConnectionPool.cs:line 33
   at Composable.Persistence.Common.AdoCE.IDbConnectionPool`2.UseConnection[TResult](Func`2 func)
   at Composable.Persistence.Common.AdoCE.IDbConnectionPool`2.UseCommand[TResult](Func`2 action)
   at Composable.Persistence.MsSql.EventStore.MsSqlEventStoreConnectionManager.UseCommand[TResult](Boolean suppressTransactionWarning, Func`2 action) in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\MsSql\EventStore\MsSqlEventStoreConnectionManager.cs:line 31
   at Composable.Persistence.MsSql.EventStore.MsSqlEventStorePersistenceLayer.<SetupSchemaIfDatabaseUnInitialized>b__10_0() in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\MsSql\EventStore\MsSqlEventStorePersistenceLayer.Schema.cs:line 17
   at Composable.SystemCE.TransactionsCE.TransactionScopeCe.Execute(Action action, TransactionScopeOption option, IsolationLevel isolationLevel) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\TransactionsCE\TransactionScopeCE.cs:line 28
   at Composable.SystemCE.TransactionsCE.TransactionScopeCe.SuppressAmbient(Action action) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\TransactionsCE\TransactionScopeCE.cs:line 13
   at Composable.Persistence.MsSql.EventStore.MsSqlEventStorePersistenceLayer.SetupSchemaIfDatabaseUnInitialized() in C:\Dev\Composable\src\framework\Composable.CQRS.ExternalDependencies\Persistence\MsSql\EventStore\MsSqlEventStorePersistenceLayer.Schema.cs:line 13
   at Composable.Persistence.EventStore.EventStore.SaveSingleAggregateEvents(IReadOnlyList`1 aggregateEvents) in C:\Dev\Composable\src\framework\Composable.CQRS\Persistence\EventStore\EventStore.cs:line 140
   at Composable.Persistence.EventStore.EventStoreUpdater.<>c__DisplayClass16_0`1.<Save>b__0(IReadOnlyList`1 events) in C:\Dev\Composable\src\framework\Composable.CQRS\Persistence\EventStore\EventStoreUpdater.cs:line 98
   at Composable.Persistence.EventStore.Aggregates.Aggregate`5.Commit(Action`1 commitEvents) in C:\Dev\Composable\src\framework\Composable.CQRS\Persistence\EventStore\Aggregates\Aggregate..cs:line 120
   at Composable.Persistence.EventStore.EventStoreUpdater.Save[TAggregate](TAggregate aggregate) in C:\Dev\Composable\src\framework\Composable.CQRS\Persistence\EventStore\EventStoreUpdater.cs:line 87
   at Composable.Tests.CQRS.EventStoreUpdaterTest.<>c__DisplayClass24_0.<Concurrent_read_only_access_to_aggregate_history_can_occur_in_parallel>b__0(IEventStoreUpdater session) in C:\Dev\Composable\src\framework\Composable.CQRS.Tests\CQRS\EventStoreUpdaterTest.cs:line 434
   at Composable.Tests.CQRS.EventStoreUpdaterTest.<>c__DisplayClass5_0.<UseInTransactionalScope>b__0() in C:\Dev\Composable\src\framework\Composable.CQRS.Tests\CQRS\EventStoreUpdaterTest.cs:line 80
   at Composable.SystemCE.TransactionsCE.TransactionScopeCe.Execute(Action action, TransactionScopeOption option, IsolationLevel isolationLevel) in C:\Dev\Composable\src\framework\Composable.CQRS\SystemCE\TransactionsCE\TransactionScopeCE.cs:line 28
   at Composable.DependencyInjection.ServiceLocatorTransactionRunner.ExecuteTransactionInIsolatedScope(IServiceLocator me, Action action) in C:\Dev\Composable\src\framework\Composable.CQRS\DependencyInjection\TransactionalExtensions.cs:line 24
   at Composable.Tests.CQRS.EventStoreUpdaterTest.UseInTransactionalScope(Action`1 useSession) in C:\Dev\Composable\src\framework\Composable.CQRS.Tests\CQRS\EventStoreUpdaterTest.cs:line 79
   at Composable.Tests.CQRS.EventStoreUpdaterTest.Concurrent_read_only_access_to_aggregate_history_can_occur_in_parallel() in C:\Dev\Composable\src\framework\Composable.CQRS.Tests\CQRS\EventStoreUpdaterTest.cs:line 434
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
   at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)


Thanks for these extra details. My current theory is that there is a thread running past the end of the main test execution and that it's getting into trouble with RDI collection while the async block winds down.

Does the test contain any mechanisms to make sure that the threads have all completed their execution before it completes?
Remco wrote:Does the test contain any mechanisms to make sure that the threads have all completed their execution before it completes?

It does. But more importantly, this exception is thrown at the beginning of the test not during teardown:



   [Test, EnableRdi(false)]
   public void Concurrent_read_only_access_to_aggregate_history_can_occur_in_parallel()
   {
      var user = new User();
      user.Register("email@email.se", "password", Guid.NewGuid());

      UseInTransactionalScope(session => session.Save(user)); // ==== Exception is thrown here ====


      var threadedIterations = 20;
      var delayEachTransactionBy = 1.Milliseconds();

      void ReadUserHistory()
      {
         UseInTransactionalScope(session =>
         {
            ((IEventStoreReader)session).GetHistory(user.Id);
            Thread.Sleep(delayEachTransactionBy);
         });
      }


      var singleThreadedExecutionTime = StopwatchCE.TimeExecution(ReadUserHistory, iterations: threadedIterations).Total;

      var timingsSummary = TimeAsserter.ExecuteThreaded(
         action: ReadUserHistory,
         iterations: threadedIterations,
         maxTotal: singleThreadedExecutionTime / 2,
         maxDegreeOfParallelism: 5,
         description: $"If access is serialized the time will be approximately {singleThreadedExecutionTime} milliseconds. If parallelized it should be far below this value.");

      timingsSummary.IndividualExecutionTimes.Sum().Should().BeGreaterThan(timingsSummary.Total, "If the sum elapsed time of the parts that run in parallel is not greater than the clock time passed parallelism is not taking place.");
   }

Edited

Thanks, I think I've isolated this issue. Would you be interested in trying out a new build with a fix included?
Remco wrote:Thanks, I think I've isolated this issue. Would you be interested in trying out a new build with a fix included?

Very much interested :)
Magnus Lidbom wrote:
Very much interested :)


Excellent. I'm nursing one through our build system at the moment and will let you know when it's available.
Ok, the new build is ready! I'm keen to hear if this solve the problem for you.

NCrunch_Console_5.12.0.1.msi
NCrunch_Console_5.12.0.1.zip
NCrunch_GridNodeServer_5.12.0.1.msi
NCrunch_GridNodeServer_5.12.0.1.zip
NCrunch_LicenseServer_5.12.0.1.zip
NCrunch_Rider_5.12.0.1.7z
NCrunch_Rider_5.12.0.1.zip
NCrunch_VS2010_5.12.0.1.msi
NCrunch_VS2010_5.12.0.1.zip
NCrunch_VS2012_5.12.0.1.msi
NCrunch_VS2012_5.12.0.1.zip
NCrunch_VS2013_5.12.0.1.msi
NCrunch_VS2013_5.12.0.1.zip
NCrunch_VS2015_5.12.0.1.msi
NCrunch_VS2015_5.12.0.1.msi.7z
NCrunch_VS2015_5.12.0.1.zip
NCrunch_VS2017_5.12.0.1.msi
NCrunch_VS2017_5.12.0.1.msi.7z
NCrunch_VS2017_5.12.0.1.zip
NCrunch_VS2019_5.12.0.1.msi
NCrunch_VS2019_5.12.0.1.msi.7z
NCrunch_VS2019_5.12.0.1.zip
NCrunch_VS2022_5.12.0.1.msi
NCrunch_VS2022_5.12.0.1.msi.7z
NCrunch_VS2022_5.12.0.1.zip
Remco wrote:Ok, the new build is ready! I'm keen to hear if this solve the problem for you.


Problem SOLVED :D
* No more NullReferenceException
* Only 7 performance tests fail now
* They fail with a loss in performance of only something like 40-60%
Heroic effort getting a fix out this fast. Thank you!

One last question Can I detect at runtime if RDI is enabled somehow? And the same question for instrumentation.
I don't mind if it is ugly and hacky as long as it works. It's just going to be used for automatically adjusting performance test expectations depending on the environment in which the test is running.

Edited

Magnus Lidbom wrote:
Problem SOLVED :D


Awesome :)

Magnus Lidbom wrote:
One last question Can I detect at runtime if RDI is enabled somehow? And the same question for instrumentation.
I don't mind if it is ugly and hacky as long as it works. It's just going to be used for automatically adjusting performance test expectations depending on the environment in which the test is running.


There isn't a way you can do this directly, but you might be able to find another way.

For example, you could detect if the test is running on your grid node by checking for an environment variable that is specific to the node.

It may also be worth reframing the question. Instead of detecting RDI, perhaps you could analyse the base speed of the machine running the test. At the start of the test, make a call to a small method that runs a tight loop for a few thousand iterations. Measure the performance, then use this measurement to adjust the tolerance of your performance test. In this way, the test is also made to be more resilient when the machine is under heavy load or is running on slow hardware.
An FYI, it's a development build so I could hardly expect it to be release quality. That said, viewing RDI information on Rider is quite glitchy. Files that work fine in visual studio do not in rider.
Clicking the brackets frequently seem to have no effect, or a dialog will eventually turn up saying that frames are loading, but they never do. Then eventually it seems to start, more or less, working.
This exception turns up pretty frequently before it starts working, sometimes later...




Details: We were unable to receive an RDI image for the current file.

java.lang.Throwable: No RDI image available
at com.intellij.openapi.diagnostic.Logger.error(Logger.java:410)
at com.remco.software.ncrunch.ErrorService$Companion.notifyUserOfError(ErrorService.kt:36)
at com.remco.software.ncrunch.editor.EditorReference.noRdiImageAvailable(EditorReference.kt:223)
at com.remco.software.ncrunch.editor.EditorReference.access$noRdiImageAvailable(EditorReference.kt:44)
at com.remco.software.ncrunch.editor.EditorReference$2.invoke(EditorReference.kt:77)
at com.remco.software.ncrunch.editor.EditorReference$2.invoke(EditorReference.kt:77)
at com.remco.software.ncrunch.editor.MemoryMapImageReceiver$startBackgroundReceiverJob$1$1.invokeSuspend$lambda$4(MemoryMapImageReceiver.kt:227)
at com.intellij.util.concurrency.ChildContext$runInChildContext$1.invoke(propagation.kt:101)
at com.intellij.util.concurrency.ChildContext$runInChildContext$1.invoke(propagation.kt:101)
at com.intellij.util.concurrency.ChildContext.runInChildContext(propagation.kt:107)
at com.intellij.util.concurrency.ChildContext.runInChildContext(propagation.kt:101)
at com.intellij.util.concurrency.ContextRunnable.run(ContextRunnable.java:27)
at java.desktop/java.awt.event.InvocationEvent.dispatch(InvocationEvent.java:318)
at java.desktop/java.awt.EventQueue.dispatchEventImpl(EventQueue.java:781)
at java.desktop/java.awt.EventQueue$4.run(EventQueue.java:728)
at java.desktop/java.awt.EventQueue$4.run(EventQueue.java:722)
at java.base/java.security.AccessController.doPrivileged(AccessController.java:400)
at java.base/java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(ProtectionDomain.java:87)
at java.desktop/java.awt.EventQueue.dispatchEvent(EventQueue.java:750)
at com.intellij.ide.IdeEventQueue.defaultDispatchEvent(IdeEventQueue.kt:675)
at com.intellij.ide.IdeEventQueue._dispatchEvent(IdeEventQueue.kt:573)
at com.intellij.ide.IdeEventQueue.dispatchEvent$lambda$18$lambda$17$lambda$16$lambda$15(IdeEventQueue.kt:355)
at com.intellij.openapi.progress.impl.CoreProgressManager.computePrioritized(CoreProgressManager.java:857)
at com.intellij.ide.IdeEventQueue.dispatchEvent$lambda$18$lambda$17$lambda$16(IdeEventQueue.kt:354)
at com.intellij.ide.IdeEventQueueKt.performActivity$lambda$2$lambda$1(IdeEventQueue.kt:1045)
at com.intellij.openapi.application.WriteIntentReadAction.lambda$run$0(WriteIntentReadAction.java:24)
at com.intellij.openapi.application.impl.AnyThreadWriteThreadingSupport.runWriteIntentReadAction(AnyThreadWriteThreadingSupport.kt:128)
at com.intellij.openapi.application.impl.ApplicationImpl.runWriteIntentReadAction(ApplicationImpl.java:916)
at com.intellij.openapi.application.WriteIntentReadAction.compute(WriteIntentReadAction.java:55)
at com.intellij.openapi.application.WriteIntentReadAction.run(WriteIntentReadAction.java:23)
at com.intellij.ide.IdeEventQueueKt.performActivity$lambda$2(IdeEventQueue.kt:1045)
at com.intellij.ide.IdeEventQueueKt.performActivity$lambda$3(IdeEventQueue.kt:1054)
at com.intellij.openapi.application.TransactionGuardImpl.performActivity(TransactionGuardImpl.java:109)
at com.intellij.ide.IdeEventQueueKt.performActivity(IdeEventQueue.kt:1054)
at com.intellij.ide.IdeEventQueue.dispatchEvent$lambda$18(IdeEventQueue.kt:349)
at com.intellij.ide.IdeEventQueue.dispatchEvent(IdeEventQueue.kt:395)
at java.desktop/java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:207)
at java.desktop/java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:128)
at java.desktop/java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:117)
at java.desktop/java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:113)
at java.desktop/java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:105)
at java.desktop/java.awt.EventDispatchThread.run(EventDispatchThread.java:92)




And like I said, the same files work in visual studio without these problem.

I hope this is useful information.

Cheers :)

Edited

Thanks for sharing this. Can you confirm how easy it is to reproduce these problems? It feels to me like they're down to race conditions between the RDI UI in Rider and the engine, which can be tough to track down. The more specific information you can feed me, the more likely I'll be able to isolate the problems.

Something that would be very helpful ... the next time you click on a bracket to open a scope, and nothing happens .. could you wait for 20 seconds, then submit an NCrunch bug report?

Edited

Remco wrote:Can you confirm how easy it is to reproduce these problems?

In my solution you basically cannot avoid them.

Remco wrote:Something that would be very helpful ... the next time you click on a bracket to open a scope, and nothing happens .. could you wait for 20 seconds, then submit an NCrunch bug report?

I was not aware of this feature. I will use it next time.

However, I figure you'd probably have the best and easiest luck tracking the problems down by mimicking my environment locally. It should be quick to set up. Code and instructions here:
https://github.com/mlidbom/Composable

Cheers :)
Two bugs submitted so far :)

What are your feelings on this, do you prefer I avoid submitting what might be duplicate problems, or do you like getting a lot of these so that you have a lot of data to work with?

Is there any way to track what happens with the stuff I submit and add additional information I find?

I assume that me mentioning thing such as whether I use Rider or VS and version of Rider/VS etc is just noise, that that is present in the gathered data. Correct?

Edited

Magnus Lidbom wrote:Two bugs submitted so far :)

Thanks :)


What are your feelings on this, do you prefer I avoid submitting what might be duplicate problems, or do you like getting a lot of these so that you have a lot of data to work with?

Is there any way to track what happens with the stuff I submit and add additional information I find?


The bug report system is basically fire-and-forget. There's no built in way to track the report or provide further communication.

It's ideal for sending through reports on issues encountered while working that are non-critical in nature. I inspect every report, though I don't always have the ability to act on them, as the logs don't always contain enough information.

It's better to report critical issues here in the forum, because in this way I can help with finding a workaround or providing a quick fix.

Magnus Lidbom wrote:
I assume that me mentioning thing such as whether I use Rider or VS and version of Rider/VS etc is just noise, that that is present in the gathered data. Correct?


Correct, this is in the report.
Would you be interested in trying the build below? It contains a stability fix for RDI under Rider. I'm hoping it might improve things around opening the scopes in your solution.

NCrunch_Console_5.12.0.2.msi
NCrunch_Console_5.12.0.2.zip
NCrunch_GridNodeServer_5.12.0.2.msi
NCrunch_GridNodeServer_5.12.0.2.zip
NCrunch_LicenseServer_5.12.0.2.zip
NCrunch_Rider_5.12.0.2.7z
NCrunch_Rider_5.12.0.2.zip
NCrunch_VS2010_5.12.0.2.msi
NCrunch_VS2010_5.12.0.2.zip
NCrunch_VS2012_5.12.0.2.msi
NCrunch_VS2012_5.12.0.2.zip
NCrunch_VS2013_5.12.0.2.msi
NCrunch_VS2013_5.12.0.2.zip
NCrunch_VS2015_5.12.0.2.msi
NCrunch_VS2015_5.12.0.2.msi.7z
NCrunch_VS2015_5.12.0.2.zip
NCrunch_VS2017_5.12.0.2.msi
NCrunch_VS2017_5.12.0.2.msi.7z
NCrunch_VS2017_5.12.0.2.zip
NCrunch_VS2019_5.12.0.2.msi
NCrunch_VS2019_5.12.0.2.msi.7z
NCrunch_VS2019_5.12.0.2.zip
NCrunch_VS2022_5.12.0.2.msi
NCrunch_VS2022_5.12.0.2.msi.7z
NCrunch_VS2022_5.12.0.2.zip
Remco wrote:Would you be interested in trying the build below? It contains a stability fix for RDI under Rider. I'm hoping it might improve things around opening the scopes in your solution.


Thanks a ton these do greatly improve the situation. It's not entirely fixed, but much better.
I sent a couple of bug reports on the remaining problems.

Post a reply

Log in to reply.