Change timer from method variable to property of SqlConnectioninteral #26495

ghost · 2021-11-01T08:04:44Z

I've read the guidelines for contributing and seen the walkthrough
I've posted a comment on an issue with a detailed description of how I am planning to contribute and got approval from a member of the team
The code builds and tests pass locally (also verified by our automated build checks)
Commit messages follow this format:

        Summary of the changes
        - Detail 1
        - Detail 2

        Fixes #bugnumber

Tests for the changes have been added (for bug fixes / features)
Issue but not a bug nor a feature. Does this need a test?
Code follows the same patterns and style as existing code in this repo

- Change timer from method variable to property of SqlConnectioninteral. Resolves #26295

…n-Wernstrom/efcore into 26295_SqliteTimerAsField

dnfadmin · 2021-11-01T08:04:57Z

All CLA requirements met.

src/Microsoft.Data.Sqlite.Core/SqliteConnectionInternal.cs

vonzshik · 2021-11-01T10:53:48Z

src/Microsoft.Data.Sqlite.Core/SqliteConnection.cs

@@ -98,6 +98,9 @@ public override string ConnectionString
        internal SqliteConnectionStringBuilder ConnectionOptions
            => PoolGroup.ConnectionOptions;

+        internal Stopwatch? Timer


I still think making it non-nullable here makes a little bit more sense since we're not supposed to access it without an internal connection (plus, it saves some !). I would have added Debug.Assert here just to make sure that _innerConnection is not null.

Implemented as per your suggestion.

vonzshik · 2021-11-01T10:57:42Z

src/Microsoft.Data.Sqlite.Core/SqliteCommand.cs

            var closeConnection = behavior.HasFlag(CommandBehavior.CloseConnection);

-            var dataReader = new SqliteDataReader(this, timer, GetStatements(timer), closeConnection);
+            var dataReader = new SqliteDataReader(this, _connection.Timer!, Statements, closeConnection);


Since we reuse a connection's timer here, we have to reset it just before we pass it to a SqliteDataReader.

Added the reset.

vonzshik · 2021-11-01T11:01:52Z

src/Microsoft.Data.Sqlite.Core/SqliteCommand.cs

            dataReader.NextResult();

            return DataReader = dataReader;
        }

-        private IEnumerable<sqlite3_stmt> GetStatements(Stopwatch timer)
+        private IEnumerable<sqlite3_stmt> Statements


Taking into account the sheer size of this method, I'm not sure we should change it into a property. There is also a potential optimization here (raised in #26494), which doesn't look that great with it being a property.

Reverted the conversion to a property.

Co-authored-by: Nikita Kazmin <vonzshik@gmail.com>

- Reset timer before passing into SqliteDataReader constructor. - Revert convertion of 'GetStatements' method to a property. - Make SqliteConnectionInternal.Timer public instead of internal. - Make SqliteConnection.Timer non-nullable.

- Remove unneccarry null forgivings.

vonzshik

Sorry for the wait, was a little bit busy with 6.0 release and other stuff. Looks, great, thank you!

vonzshik · 2021-11-19T16:21:18Z

Benchmarked the change.

Before (main):

BenchmarkDotNet=v0.12.1, OS=Windows 10.0.19042
AMD Ryzen 5 5600X, 1 CPU, 12 logical and 6 physical cores
.NET Core SDK=6.0.100
  [Host]     : .NET Core 6.0.0 (CoreCLR 6.0.21.52210, CoreFX 6.0.21.52210), X64 RyuJIT
  DefaultJob : .NET Core 6.0.0 (CoreCLR 6.0.21.52210, CoreFX 6.0.21.52210), X64 RyuJIT

Method	Mean	Error	StdDev	Op/s	Gen 0	Gen 1	Gen 2	Allocated
SelectOne	313.8 ns	1.00 ns	0.89 ns	3,187,115.3	0.0186	-	-	312 B

After (Dr-Ogden-Wernstrom:26295_SqliteTimerAsField):

BenchmarkDotNet=v0.12.1, OS=Windows 10.0.19042
AMD Ryzen 5 5600X, 1 CPU, 12 logical and 6 physical cores
.NET Core SDK=6.0.100
  [Host]     : .NET Core 6.0.0 (CoreCLR 6.0.21.52210, CoreFX 6.0.21.52210), X64 RyuJIT
  DefaultJob : .NET Core 6.0.0 (CoreCLR 6.0.21.52210, CoreFX 6.0.21.52210), X64 RyuJIT

Method	Mean	Error	StdDev	Op/s	Gen 0	Gen 1	Gen 2	Allocated
SelectOne	299.0 ns	1.73 ns	1.44 ns	3,344,267.4	0.0153	-	-	256 B

Benchmark code

public class Prepared
{
	private readonly SqliteCommand command;

	public Prepared()
	{
		var csb = new SqliteConnectionStringBuilder
		{
			DataSource = ":memory:",
		};

		var conn = new SqliteConnection(csb.ToString());
		conn.Open();

		command = conn.CreateCommand();
		command.CommandText = "SELECT 1";
		command.Prepare();
	}

	[Benchmark]
	[MethodImpl(MethodImplOptions.NoInlining)]
	public object? SelectOne() => command.ExecuteScalar();
}

…n-Wernstrom/efcore into 26295_SqliteTimerAsField

ghost · 2021-12-02T19:03:43Z

@vonzshik @bricelam Is there anything I need to do to get the PR completed?

vonzshik · 2021-12-03T10:35:16Z

@Dr-Ogden-Wernstrom I'm afraid, we just have to wait for @bricelam to review: he's the one responsible for Sqlite from efcore team.

ghost · 2021-12-03T10:38:41Z

Thanks @vonzshik. My first PR on GitHub so just wanted to make sure it wasn't sitting with me unawares.

bricelam · 2022-01-25T22:42:51Z

src/Microsoft.Data.Sqlite.Core/SqliteCommand.cs

            var closeConnection = behavior.HasFlag(CommandBehavior.CloseConnection);

-            var dataReader = new SqliteDataReader(this, timer, GetStatements(timer), closeConnection);
+            _connection.Timer.Reset();


This doesn't seem right to me. A connection can have multiple readers open at the same time. I'm pretty sure we need a new instance for every reader...

Would using something like ValueStopwatch instead also help perf?

See dotnet/runtime#48570 for some discussion on ValueStopWatch (which was closed for some reason).

If we don't do ValueStopWatch, we can still "pool" a single StopWatch instance on the connection, so that uses which don't involve multiple open readers can benefit (but those with multiple readers would allocate).

Huh, didn't know Sqlite supported MARS...

To me, using ValueStopwatch seems to be the simplest solution (in a sense that there is no pooling involved, which does complicate things a bit), but pooling is also fine.

Okay, ValueStopwatch in a way it's implemented in ASP.NET Core wouldn't work here. The main offender is SqliteDataReader:

efcore/src/Microsoft.Data.Sqlite.Core/SqliteDataReader.cs

Lines 157 to 173 in afe299f

_timer.Start();

while (IsBusy(rc = sqlite3_step(stmt)))

{

if (_command.CommandTimeout != 0

&& _timer.ElapsedMilliseconds >= _command.CommandTimeout * 1000L)

{

break;

}

sqlite3_reset(stmt);

// TODO: Consider having an async path that uses Task.Delay()

Thread.Sleep(150);

}

_timer.Stop();

Every time a NextResult is called on a reader the timer isn't reset, but continues to measure the elapsed time from where it left on a previous call.

If we don't do ValueStopWatch, we can still "pool" a single StopWatch instance on the connection, so that uses which don't involve multiple open readers can benefit (but those with multiple readers would allocate).

@roji Could this be something as simple as allocating a new Stopwatch if the connection has multiple commands like my latest change?

Every time a NextResult is called on a reader the timer isn't reset, but continues to measure the elapsed time from where it left on a previous call.

@vonzshik My initial feeling is that adding stop/start functionality to ValueStopwatch would result in something almost the same as the standard Stopwatch implementation, so not much benefit. What do you think?

@vonzshik My initial feeling is that adding stop/start functionality to ValueStopwatch would result in something almost the same as the standard Stopwatch implementation, so not much benefit. What do you think?

Well, there is the fun fact that both SqliteCommand.PrepareAndEnumerateStatements and SqliteDataReader.NextResult are supposed to use the exact same instance of Stopwatch and the result from SqliteCommand.PrepareAndEnumerateStatements is passed as IEnumerable to the reader...

efcore/src/Microsoft.Data.Sqlite.Core/SqliteCommand.cs

Line 313 in 802d4c5

var dataReader = new SqliteDataReader(this, timer, GetStatements(timer), closeConnection);

Hey @vonzshik, that is a fun fact.
Sorry, I've been so slow getting to this, and for being a total noob on this project, but would you mind taking another look, please.

bricelam · 2022-06-07T20:58:27Z

I'm going to run our SQLite benchmarks to see the impact of this change, then I'll discuss it with the team.

bricelam · 2022-06-07T22:58:10Z

	Before	After
CPU Usage (%)	54	57
Working Set (MB)	394	396
Requests/sec	29,055	28,704
Mean latency (ms)	8.83	8.92

vonzshik · 2022-06-08T06:48:42Z

@bricelam that's interesting, since I do see a small improvements in a simple benchmark

BenchmarkDotNet=v0.13.1, OS=Windows 10.0.19044.1706 (21H2)
AMD Ryzen 5 5600X, 1 CPU, 12 logical and 6 physical cores
.NET SDK=7.0.100-preview.4.22252.9
  [Host]     : .NET 7.0.0 (7.0.22.22904), X64 RyuJIT
  DefaultJob : .NET 7.0.0 (7.0.22.22904), X64 RyuJIT

From

Method	Mean	Error	StdDev	Op/s	Gen 0	Allocated
SelectOne	277.5 ns	0.70 ns	0.59 ns	3,603,227.7	0.0186	312 B

To

Method	Mean	Error	StdDev	Op/s	Gen 0	Allocated
SelectOne	274.8 ns	0.86 ns	0.81 ns	3,639,623.7	0.0162	272 B

Code

public class Prepared
{
	private readonly SqliteCommand command;

	public Prepared()
	{
		var csb = new SqliteConnectionStringBuilder
		{
			DataSource = ":memory:",
		};

		var conn = new SqliteConnection(csb.ToString());
		conn.Open();

		command = conn.CreateCommand();
		command.CommandText = "SELECT 1";
		command.Prepare();
	}

	[Benchmark]
	[MethodImpl(MethodImplOptions.NoInlining)]
	public object? SelectOne() => command.ExecuteScalar();
}

Though, the main point here was to reduce allocations, which it does. To improve the rps, I was thinking on rewriting SqliteCommand.GetStatements to something like this:

private IEnumerable<sqlite3_stmt> GetStatements(Stopwatch timer)
{
	if (_prepared)
	{
		for (var statementIndex = 0; statementIndex < _preparedStatements.Count; statementIndex++)
		{
			(var stmt, var expectedParams) = _preparedStatements[statementIndex];

			yield return GetStatementsCore(stmt, expectedParams, _parameters, timer);
		}
	}
	else
	{
		foreach ((var stmt, var expectedParams) in PrepareAndEnumerateStatements(timer))
		{
			yield return GetStatementsCore(stmt, expectedParams, _parameters, timer);
		}
	}

	static sqlite3_stmt GetStatementsCore(sqlite3_stmt stmt, int expectedParams, SqliteParameterCollection? parameters, Stopwatch timer)
	{
		var boundParams = parameters?.Bind(stmt) ?? 0;

		if (expectedParams != boundParams)
		{
			var unboundParams = new List<string>();
			for (var i = 1; i <= expectedParams; i++)
			{
				var name = sqlite3_bind_parameter_name(stmt, i).utf8_to_string();

				if (parameters != null
					&& !parameters.Cast<SqliteParameter>().Any(p => p.ParameterName == name))
				{
					unboundParams.Add(name);
				}
			}

			if (sqlite3_libversion_number() < 3028000 || sqlite3_stmt_isexplain(stmt) == 0)
			{
				throw new InvalidOperationException(Resources.MissingParameters(string.Join(", ", unboundParams)));
			}
		}

		return stmt;
	}
}

Which gives a nice rps bump, while also reducing allocations:

Method	Mean	Error	StdDev	Op/s	Gen 0	Allocated
SelectOne	256.9 ns	0.89 ns	0.84 ns	3,893,317.3	0.0138	232 B

Before After
CPU Usage (%) 54 57
Working Set (MB) 394 396
Requests/sec 29,055 28,704
Mean latency (ms) 8.83 8.92

I assume you were running Orchard benchmark? I'll try to take a look in the next few days.

bricelam · 2022-06-08T16:41:21Z

I'm using the TechEmpower Fortunes benchmark (technically not valid for TechEmpower since the database doesn't run on a separate server).

crank --scenario fortunes --profile sqlite --config https://raw.githubusercontent.com/aspnet/Benchmarks/main/scenarios/database.benchmarks.yml

It's also worth noting that we haven't done any performance work on this driver. Instead, I wanted to tackle the bigger architectural wins like #14044 first. I also want to re-implement the connection pool. I used the generic ADO.NET code as a starting point, but in hindsight, that was a mistake.

ajcvickers · 2022-06-13T11:03:39Z

@vonzshik We really appreciate your work on this, but we discussed this as a team, and given the code is a little more complex and the performance results are not compelling, we have decided not to merge this.

Russell-Horwood-Xceptor and others added 4 commits October 31, 2021 21:50

Host timer as property on SqliteConnectionInternal.

d03467f

Merge branch 'dotnet:main' into 26295_SqliteTimerAsField

a5b7dee

Summary of the changes

97fbfed

- Change timer from method variable to property of SqlConnectioninteral. Resolves #26295

Merge branch '26295_SqliteTimerAsField' of https://github.com/Dr-Ogde…

2c0520a

…n-Wernstrom/efcore into 26295_SqliteTimerAsField

vonzshik reviewed Nov 1, 2021

View reviewed changes

Dr-Ogden-Wernstrom and others added 4 commits November 1, 2021 16:07

Update src/Microsoft.Data.Sqlite.Core/SqliteConnectionInternal.cs

0581078

Co-authored-by: Nikita Kazmin <vonzshik@gmail.com>

Summary of the changes

af8f49f

- Reset timer before passing into SqliteDataReader constructor. - Revert convertion of 'GetStatements' method to a property. - Make SqliteConnectionInternal.Timer public instead of internal. - Make SqliteConnection.Timer non-nullable.

Merge from remote.

e9ba6d3

Summary of the changes

1abe9e8

- Remove unneccarry null forgivings.

ajcvickers assigned bricelam Nov 2, 2021

vonzshik approved these changes Nov 19, 2021

View reviewed changes

Dr-Ogden-Wernstrom and others added 2 commits November 19, 2021 15:43

Merge branch 'main' into 26295_SqliteTimerAsField

2431c1d

Fix my merge-by-eye fail.

827b12e

Russell-Horwood-Xceptor added 4 commits November 19, 2021 17:30

Fix my merge-by-eye fail.

44ca0ca

Merge branch '26295_SqliteTimerAsField' of https://github.com/Dr-Ogde…

08a8b2a

…n-Wernstrom/efcore into 26295_SqliteTimerAsField

Merge branch '26295_SqliteTimerAsField' of https://github.com/Dr-Ogde…

f5649e9

…n-Wernstrom/efcore into 26295_SqliteTimerAsField

Merge branch '26295_SqliteTimerAsField' of https://github.com/Dr-Ogde…

7d53c2d

…n-Wernstrom/efcore into 26295_SqliteTimerAsField

ghost closed this Nov 20, 2021

ghost reopened this Nov 20, 2021

bricelam suggested changes Jan 25, 2022

View reviewed changes

bricelam added the waiting-for-response label Jan 25, 2022

Russell-Horwood-Xceptor added 3 commits February 6, 2022 14:46

Merge branch 'main' into 26295_SqliteTimerAsField

dfd9adc

Instantiate timer iff the command is the only one on the connection

685a862

Same timer prepare and reading statements

f2ef784

bricelam removed the waiting-for-response label Feb 28, 2022

bricelam added the needs-design label Jun 7, 2022

ajcvickers closed this Jun 13, 2022

ajcvickers mentioned this pull request Jul 13, 2022

SqliteCommand allocates one Stopwatch per every query or prepare #26295

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Change timer from method variable to property of SqlConnectioninteral #26495

Change timer from method variable to property of SqlConnectioninteral #26495

ghost commented Nov 1, 2021 •

edited by ghost

Loading

dnfadmin commented Nov 1, 2021 •

edited

Loading

vonzshik Nov 1, 2021

ghost Nov 1, 2021

vonzshik Nov 1, 2021

ghost Nov 1, 2021

vonzshik Nov 1, 2021

ghost Nov 1, 2021

vonzshik left a comment

vonzshik commented Nov 19, 2021

ghost commented Dec 2, 2021

vonzshik commented Dec 3, 2021

ghost commented Dec 3, 2021

bricelam Jan 25, 2022

bricelam Jan 25, 2022

roji Jan 26, 2022 •

edited

Loading

vonzshik Jan 26, 2022 •

edited

Loading

vonzshik Jan 26, 2022

ghost Feb 6, 2022

vonzshik Feb 7, 2022

ghost Feb 21, 2022

bricelam commented Jun 7, 2022

bricelam commented Jun 7, 2022

vonzshik commented Jun 8, 2022

bricelam commented Jun 8, 2022

ajcvickers commented Jun 13, 2022

	_timer.Start();

	while (IsBusy(rc = sqlite3_step(stmt)))
	{
	if (_command.CommandTimeout != 0
	&& _timer.ElapsedMilliseconds >= _command.CommandTimeout * 1000L)
	{
	break;
	}

	sqlite3_reset(stmt);

	// TODO: Consider having an async path that uses Task.Delay()
	Thread.Sleep(150);
	}

	_timer.Stop();

Change timer from method variable to property of SqlConnectioninteral #26495

Change timer from method variable to property of SqlConnectioninteral #26495

Conversation

ghost commented Nov 1, 2021 • edited by ghost Loading

dnfadmin commented Nov 1, 2021 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

vonzshik left a comment

Choose a reason for hiding this comment

vonzshik commented Nov 19, 2021

ghost commented Dec 2, 2021

vonzshik commented Dec 3, 2021

ghost commented Dec 3, 2021

Choose a reason for hiding this comment

Choose a reason for hiding this comment

roji Jan 26, 2022 • edited Loading

Choose a reason for hiding this comment

vonzshik Jan 26, 2022 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

bricelam commented Jun 7, 2022

bricelam commented Jun 7, 2022

vonzshik commented Jun 8, 2022

bricelam commented Jun 8, 2022

ajcvickers commented Jun 13, 2022

ghost commented Nov 1, 2021 •

edited by ghost

Loading

dnfadmin commented Nov 1, 2021 •

edited

Loading

roji Jan 26, 2022 •

edited

Loading

vonzshik Jan 26, 2022 •

edited

Loading