Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

test (with sqlite db) randomly fails #19065

Closed
1 task done
puschie286 opened this issue Feb 16, 2024 · 13 comments · Fixed by #19125
Closed
1 task done

test (with sqlite db) randomly fails #19065

puschie286 opened this issue Feb 16, 2024 · 13 comments · Fixed by #19125
Assignees
Milestone

Comments

@puschie286
Copy link

puschie286 commented Feb 16, 2024

Is there an existing issue for this?

  • I have searched the existing issues

Description

We notice that some test randomly fail with "Index was out of range" exception - same like here. Sometimes it happen right away, after a few (5) iterations or only after more than 1k iterations.

The exception state that the sqlite connection is shared between multiple test in some rare cases or that some operations are still running after the test is done and the connection is reused in the next test.

We use a permission test for investigation and notice some "strange" behavior:

  • happen more often when seeding is disabled (in TestBaseModule)
  • GetListAsync with names doesnt trigger the problem, only GetListAsync without does it (to get all)

Exception:

System.ArgumentOutOfRangeException: Index was out of range. Must be non-negative and less than the size of the collection. (Parameter 'index')

System.ArgumentOutOfRangeException
Index was out of range. Must be non-negative and less than the size of the collection. (Parameter 'index')
   at System.Collections.Generic.List`1.RemoveAt(Int32 index)
   at Microsoft.Data.Sqlite.SqliteConnection.RemoveCommand(SqliteCommand command)
   at Microsoft.Data.Sqlite.SqliteCommand.Dispose(Boolean disposing)
   at System.ComponentModel.Component.Dispose()
   at System.Data.Common.DbCommand.DisposeAsync()
   at Microsoft.EntityFrameworkCore.Storage.RelationalDataReader.DisposeAsync()
   at Microsoft.EntityFrameworkCore.EntityFrameworkQueryableExtensions.ToListAsync[TSource](IQueryable`1 source, CancellationToken cancellationToken)
   at Volo.Abp.PermissionManagement.EntityFrameworkCore.EfCorePermissionGrantRepository.GetListAsync(String providerName, String providerKey, CancellationToken cancellationToken)
   at Castle.DynamicProxy.AsyncInterceptorBase.ProceedAsynchronous[TResult](IInvocation invocation, IInvocationProceedInfo proceedInfo)
   at Volo.Abp.Castle.DynamicProxy.CastleAbpMethodInvocationAdapterWithReturnValue`1.ProceedAsync()
   at Volo.Abp.Uow.UnitOfWorkInterceptor.InterceptAsync(IAbpMethodInvocation invocation)
   at Volo.Abp.Castle.DynamicProxy.CastleAsyncAbpInterceptorAdapter`1.InterceptAsync[TResult](IInvocation invocation, IInvocationProceedInfo proceedInfo, Func`3 proceed)
   at RandomTestFail.EntityFrameworkCore.Test.Seeder.SeedAsync(String providerName, String providerKey, IEnumerable`1 grantedPermissions, Nullable`1 tenantId) in ***RandomTestFail\test\RandomTestFail.EntityFrameworkCore.Tests\EntityFrameworkCore\Test\Seeder.cs:line 33
   at RandomTestFail.EntityFrameworkCore.Test.SeederTests.Test2() in ***RandomTestFail\test\RandomTestFail.EntityFrameworkCore.Tests\EntityFrameworkCore\Test\SeederTests.cs:line 50
   at Xunit.Sdk.TestInvoker`1.<>c__DisplayClass48_0.<<InvokeTestMethodAsync>b__1>d.MoveNext() in /_/src/xunit.execution/Sdk/Frameworks/Runners/TestInvoker.cs:line 285
--- End of stack trace from previous location ---
   at Xunit.Sdk.ExecutionTimer.AggregateAsync(Func`1 asyncAction) in /_/src/xunit.execution/Sdk/Frameworks/ExecutionTimer.cs:line 48
   at Xunit.Sdk.ExceptionAggregator.RunAsync(Func`1 code) in /_/src/xunit.core/Sdk/ExceptionAggregator.cs:line 90

Permission Test:

using System.Threading.Tasks;
using Shouldly;
using Volo.Abp.PermissionManagement;
using Xunit;

namespace RandomTestFail.EntityFrameworkCore.Test;

public sealed class SeederTests : RandomTestFailEntityFrameworkCoreTestBase
{
	private readonly IPermissionDataSeeder      _seeder;
	private readonly IPermissionGrantRepository _repository;

	private const string Name = "ExampleName";
	private const string Key  = "ExampleKey";

	private const string Permission1 = "Permission1";
	private const string Permission2 = "Permission2";

	public SeederTests()
	{
		_repository = GetRequiredService<IPermissionGrantRepository>();
		_seeder     = GetRequiredService<IPermissionDataSeeder>();
	}

	private Task Seed( params string[] grantedPermission )
	{
		return _seeder.SeedAsync( Name, Key, grantedPermission );
	}

	private async Task<bool> FindPermission( string permission )
	{
		return await _repository.FindAsync( permission, Name, Key ) != null;
	}

	[Fact]
	public async Task Test1()
	{
		// Arrange & Act
		await Seed( Permission1, Permission2 );

		// Assert
		( await FindPermission( Permission1 ) ).ShouldBeTrue();
		( await FindPermission( Permission2 ) ).ShouldBeTrue();
	}

	[Fact]
	public async Task Test2()
	{
		// Arrange & Act
		await Seed( Permission1, Permission2 );

		// Assert
		( await FindPermission( Permission1 ) ).ShouldBeTrue();
		( await FindPermission( Permission2 ) ).ShouldBeTrue();
	}
}

Custom Seeder: (Identical to PermissionDataSeeder except using GetListAsync without names parameter)

using System;
using System.Collections.Generic;
using System.Linq;
using System.Threading.Tasks;
using Microsoft.Extensions.DependencyInjection;
using Volo.Abp.DependencyInjection;
using Volo.Abp.Guids;
using Volo.Abp.MultiTenancy;
using Volo.Abp.PermissionManagement;

namespace RandomTestFail.EntityFrameworkCore.Test;

[Dependency( ServiceLifetime.Transient, ReplaceServices = true )]
[ExposeServices( typeof( IPermissionDataSeeder ) )]
public class Seeder(
	IPermissionGrantRepository permissionGrantRepository,
	IGuidGenerator guidGenerator,
	ICurrentTenant currentTenant ) : IPermissionDataSeeder, ITransientDependency
{
	private IPermissionGrantRepository PermissionGrantRepository { get; } = permissionGrantRepository;
	private IGuidGenerator             GuidGenerator             { get; } = guidGenerator;
	private ICurrentTenant             CurrentTenant             { get; } = currentTenant;

	public async Task SeedAsync(
		string providerName,
		string providerKey,
		IEnumerable<string> grantedPermissions,
		Guid? tenantId = null )
	{
		using( CurrentTenant.Change( tenantId ) )
		{
			var names = grantedPermissions.ToArray();
			var existsPermissionGrants = ( await PermissionGrantRepository.GetListAsync( providerName, providerKey ) )
				.Select( x => x.Name )
				.ToList();

			foreach( var permissionName in names.Except( existsPermissionGrants ) )
			{
				await PermissionGrantRepository.InsertAsync(
					new PermissionGrant( GuidGenerator.Create(), permissionName, providerName, providerKey, tenantId )
				);
			}
		}
	}
}

Reproduction Steps

  1. Copy "Permission Test" and "Seeder" to EntityFrameworkCore.Tests project
  2. comment out SeedTestData in TestBaseModule.OnApplicationInitialization
  3. Run Permission test in Loop until failure

Expected behavior

Endless clean runs

Actual behavior

Test throw exception after a few run

Regression?

No response

Known Workarounds

With seeding enabled and disposing of sqlite connection after application shutdown has called (OnPostApplicationShutdown) seems to prevent this problem (1k runs without fail)

Version

8.0.3

User Interface

MVC

Database Provider

EF Core (Default)

Tiered or separate authentication server

None (Default)

Operation System

Windows (Default)

Other information

Test project:
RandomTestFail.zip

@puschie286 puschie286 added the bug label Feb 16, 2024
@maliming maliming self-assigned this Feb 17, 2024
@maliming
Copy link
Member

hi

Please add your code to the test project and reshare it. Thanks.

@puschie286
Copy link
Author

puschie286 commented Feb 17, 2024

@maliming the test project contain these files - in the entity framework core test project

@maliming
Copy link
Member

hi

I think this is an EF Core-related issue. It's fixed on 9.0.0-preview1

dotnet/efcore#22921

@maliming maliming removed the bug label Feb 19, 2024
@puschie286
Copy link
Author

thanks for pointing that out - hopefully this will be included in an (LTS) dotnet 8 update

@maliming
Copy link
Member

hi @puschie286

A temporary solution

private static SqliteConnection CreateDatabaseAndGetConnection()
{
    var connection = new AbpSqliteConnection("Data Source=:memory:");
    connection.Open();

    var options = new DbContextOptionsBuilder<MyProjectNameDbContext>()
        .UseSqlite(connection)
        .Options;

    using (var context = new MyProjectNameDbContext(options))
    {
        context.GetService<IRelationalDatabaseCreator>().CreateTables();
    }

    return connection;
}
using System;
using System.Collections.Generic;
using System.Data;
using System.Diagnostics;
using System.Reflection;
using Microsoft.Data.Sqlite;

namespace MyCompanyName.MyProjectName.EntityFrameworkCore;

public class AbpSqliteConnection : SqliteConnection
{
    public AbpSqliteConnection(string connectionString)
        : base(connectionString)
    {
    }

    public override void Close()
    {
        if (State != ConnectionState.Open)
        {
            return;
        }

        Transaction?.Dispose();

        var baseCommands = typeof(SqliteConnection).GetField("_commands", BindingFlags.NonPublic | BindingFlags.Instance).GetValue(this).As<List<WeakReference<SqliteCommand>>>();

        var commands = baseCommands;
        for (var i = commands.Count - 1; i >= 0; i--)
        {
            var reference = commands[i];
            if (reference.TryGetTarget(out var command))
            {
                // NB: Calls RemoveCommand()
                command.Dispose();
            }
            else
            {
                baseCommands.Remove(reference);
            }
        }

        Debug.Assert(baseCommands.Count == 0);

        baseCommands.Clear();

        var baseInnerConnection = typeof(SqliteConnection).GetField("_innerConnection", BindingFlags.NonPublic | BindingFlags.Instance).GetValue(this);

        var closeMethod = baseInnerConnection!.GetType().GetMethod("Close", BindingFlags.Public | BindingFlags.Instance);
        closeMethod.Invoke(baseInnerConnection, null);
        baseInnerConnection = null;

        var baseState = typeof(SqliteConnection).GetField("_state", BindingFlags.NonPublic | BindingFlags.Instance).GetValue(this).To<ConnectionState>();
        baseState = ConnectionState.Closed;

        var baseFromOpenToClosedEventArgs = typeof(SqliteConnection).GetField("_fromOpenToClosedEventArgs", BindingFlags.NonPublic | BindingFlags.Instance | BindingFlags.Static).GetValue(this).As<StateChangeEventArgs>();
        OnStateChange(baseFromOpenToClosedEventArgs);
    }
}

@puschie286
Copy link
Author

@maliming thanks for your effort

Unfortunately, it does not solve the problem - i think it may be related to some other problem that cause the connection to be accessed from multiple threads at the same time

in the callstack you see the call of
RelationalDataReader.DisposeAsync
right after entering
EntityFrameworkQueryableExtensions.ToListAsync
that leads to the exception.

It shows that the execution of the RemoveCommand method (probably from another thread) overlaps with the Close method execution (these are the only places remove entries from the _command list)

We created a version that lock before iterating over commands in Close/RemoveCommand and this seems to prevent the problem.

FixedSqlCommand

using System.ComponentModel;
using System.Reflection;

namespace Microsoft.Data.Sqlite;

public class FixedSqlCommand : SqliteCommand
{
	private static MethodInfo? _disposePreparedStatementsMethod;
	private static FieldInfo?  _connectionField;
	private static FieldInfo?  _eventsField;
	private static FieldInfo?  _eventDisposedField;

	private void DisposePreparedStatements( bool disposing )
	{
		if( _disposePreparedStatementsMethod == null )
		{
			_disposePreparedStatementsMethod = typeof( SqliteCommand ).GetMethod( "DisposePreparedStatements", BindingFlags.NonPublic | BindingFlags.Instance )!;
		}

		_disposePreparedStatementsMethod.Invoke( this, [disposing] );
	}

	private FixedSqlConnection? GetConnection()
	{
		if( _connectionField == null )
		{
			_connectionField = typeof( SqliteCommand ).GetField( "_connection", BindingFlags.NonPublic | BindingFlags.Instance )!;
		}

		return _connectionField.GetValue( this )?.As<FixedSqlConnection>();
	}

	private EventHandlerList? GetEvents()
	{
		if( _eventsField == null )
		{
			_eventsField = typeof( Component ).GetField( "_events", BindingFlags.NonPublic | BindingFlags.Instance )!;
		}

		return _eventsField.GetValue( this )?.As<EventHandlerList>();
	}

	private object GetEventDisposed()
	{
		if( _eventDisposedField == null )
		{
			_eventDisposedField = typeof( Component ).GetField( "s_eventDisposed", BindingFlags.NonPublic | BindingFlags.Static )!;
		}

		return _eventDisposedField.GetValue( this )!;
	}

	private void ComponentsDispose( bool disposing )
	{
		if( disposing )
		{
			lock( this )
			{
				Container?.Remove( this );
				EventHandlerList? events = GetEvents();
				if( events != null )
				{
					object eventDisposed = GetEventDisposed();
					( (EventHandler?)events[eventDisposed] )?.Invoke( this, EventArgs.Empty );
				}
			}
		}
	}

	protected override void Dispose( bool disposing )
	{
		DisposePreparedStatements( disposing );

		if( disposing )
		{
			GetConnection()?.RemoveCommand( this );
		}

		ComponentsDispose( disposing );
	}
}

FixedSqlConnection

using System.Data;
using System.Diagnostics;
using System.Reflection;

namespace Microsoft.Data.Sqlite;

public class FixedSqlConnection( string connectionString ) : SqliteConnection( connectionString )
{
	private static FieldInfo?  _commandField;
	private static FieldInfo?  _innerConnectionField;
	private static FieldInfo?  _stateField;
	private static FieldInfo?  _fromOpenToClosedEventArgsField;
	private static MethodInfo? _innerConnectionCloseMethod;

	private List<WeakReference<SqliteCommand>> GetCommand()
	{
		if( _commandField == null )
		{
			_commandField = typeof( SqliteConnection ).GetField( "_commands", BindingFlags.NonPublic | BindingFlags.Instance )!;
		}

		return _commandField.GetValue( this )?.As<List<WeakReference<SqliteCommand>>>()!;
	}

	private void CloseInnerConnection()
	{
		if( _innerConnectionField == null )
		{
			_innerConnectionField = typeof( SqliteConnection ).GetField( "_innerConnection", BindingFlags.NonPublic | BindingFlags.Instance )!;
		}

		object instance = _innerConnectionField.GetValue( this )!;
		if( _innerConnectionCloseMethod == null )
		{
			_innerConnectionCloseMethod = instance.GetType().GetMethod( "Close", BindingFlags.Public | BindingFlags.Instance )!;
		}

		_innerConnectionCloseMethod.Invoke( instance, null );
		_innerConnectionField.SetValue( this, null );
	}

	private void SetCloseState( ConnectionState state )
	{
		if( _stateField == null )
		{
			_stateField = typeof( SqliteConnection ).GetField( "_state", BindingFlags.NonPublic | BindingFlags.Instance )!;
		}

		_stateField.SetValue( this, state );
	}

	private StateChangeEventArgs GetChangeEventArgs()
	{
		if( _fromOpenToClosedEventArgsField == null )
		{
			_fromOpenToClosedEventArgsField = typeof( SqliteConnection ).GetField( "_fromOpenToClosedEventArgs", BindingFlags.NonPublic | BindingFlags.Static )!;
		}

		return _fromOpenToClosedEventArgsField.GetValue( this )?.As<StateChangeEventArgs>()!;
	}

	public override void Close()
	{
		if( State != ConnectionState.Open )
		{
			return;
		}

		Transaction?.Dispose();

		List<WeakReference<SqliteCommand>> _commands = GetCommand();
		lock( this )
		{
			for( int i = _commands.Count - 1; i >= 0; i-- )
			{
				if( _commands[i].TryGetTarget( out SqliteCommand? command ) )
				{
					command.Dispose();
				}
				else
				{
					_commands.RemoveAt( i );
				}
			}

			Debug.Assert( _commands.Count == 0 );
			_commands.Clear();
		}

		CloseInnerConnection();

		SetCloseState( ConnectionState.Closed );
		OnStateChange( GetChangeEventArgs() );
	}

	public override SqliteCommand CreateCommand() => new FixedSqlCommand
	{
		Connection     = this,
		CommandTimeout = DefaultTimeout,
		Transaction    = Transaction
	};

	public void RemoveCommand( FixedSqlCommand command )
	{
		List<WeakReference<SqliteCommand>> _commands = GetCommand();
		lock( this )
		{
			for( int i = _commands.Count - 1; i >= 0; i-- )
			{
				if( _commands[i].TryGetTarget( out SqliteCommand? item ) && item == command )
				{
					_commands.RemoveAt( i );
				}
			}
		}
	}
}

@maliming
Copy link
Member

I copied their latest code. This means that EF Core didn't fix the problem at all.

@puschie286
Copy link
Author

yes - the question is if this is related to the test setup in abp or dotnet implementation of some other function

@maliming
Copy link
Member

Our unit tests are concurrent, but sqlite may have a problem with that.

We can have the unit tests run sequentially in our project rather than concurrently, but it's best if sqlite is compatible with this case.

@maliming maliming reopened this Feb 23, 2024
@maliming
Copy link
Member

I will make some compatibility code.

@maliming maliming added this to the 8.2-preview milestone Feb 23, 2024
@maliming
Copy link
Member

hi @puschie286

Can you test the code below? It works on RandomTestFail.zip

using System.Threading;
using Microsoft.Data.Sqlite;
using Volo.Abp.Threading;

namespace RandomTestFail.EntityFrameworkCore;

public class AbpSqliteConnection : SqliteConnection
{
	public AbpSqliteConnection(string connectionString)
		: base(connectionString)
	{
	}

	public override SqliteCommand CreateCommand()
	{
		var command = new AbpSqliteCommand();
		command.Connection = this;
		command.CommandTimeout = DefaultTimeout;
		command.Transaction = Transaction;
		return command;
	}
}

public class AbpSqliteCommand : SqliteCommand
{
	private static readonly SemaphoreSlim SyncSemaphore = new SemaphoreSlim(1, 1);

	public override SqliteConnection? Connection
	{
		get => base.Connection;
		set
		{
			using (SyncSemaphore.Lock())
			{
				base.Connection = value;
			}
		}
	}

	protected override void Dispose(bool disposing)
	{
		using (SyncSemaphore.Lock())
		{
			base.Dispose(disposing);
		}
	}
}

@puschie286
Copy link
Author

@maliming hi, yes, seems to work

@maliming
Copy link
Member

ok, I will add it to the framework.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants