diff --git a/.editorconfig b/.editorconfig index e2f0c4ea8..ee08af36d 100644 --- a/.editorconfig +++ b/.editorconfig @@ -10,6 +10,9 @@ dotnet_analyzer_diagnostic.severity = error # Namespace does not match folder structure - Ideally this should be enabled but it seems to have issues with root level files so disabling for now dotnet_diagnostic.IDE0130.severity = none +# CA1805: Do not initialize unnecessarily - It's better to be explicit when initializing vars to ensure correct value is used +dotnet_diagnostic.CA1805.severity = none + # Documentation related errors, remove once they are fixed dotnet_diagnostic.CS1591.severity = none dotnet_diagnostic.CS1573.severity = none diff --git a/README.md b/README.md index 9843298af..0e4b93d4c 100644 --- a/README.md +++ b/README.md @@ -8,6 +8,7 @@ This repository contains the Azure SQL bindings for Azure Functions extension co - [**Input Binding**](#input-binding-tutorial): takes a SQL query to run and returns the output of the query in the function. - [**Output Binding**](#output-binding-tutorial): takes a list of rows and upserts them into the user table (i.e. If a row doesn't already exist, it is added. If it does, it is updated). +- [**Trigger Binding**](#trigger-binding-tutorial): monitors the user table for changes (i.e., row inserts, updates, and deletes) and invokes the function with updated rows. Further information on the Azure SQL binding for Azure Functions is also available in the [Azure Functions docs](https://docs.microsoft.com/azure/azure-functions/functions-bindings-azure-sql). @@ -31,9 +32,23 @@ Azure SQL bindings for Azure Functions are supported for: - [Configure Function App](#configure-function-app) - [Tutorials](#tutorials) - [.NET functions](#net-functions) + - [Input Binding Tutorial](#input-binding-tutorial) + - [Output Binding Tutorial](#output-binding-tutorial) + - [Trigger Binding Tutorial](#trigger-binding-tutorial) - [JavaScript functions](#javascript-functions) + - [Input Binding Tutorial](#input-binding-tutorial-1) + - [Output Binding Tutorial](#output-binding-tutorial-1) - [Python functions](#python-functions) + - [Input Binding Tutorial](#input-binding-tutorial-2) + - [Output Binding Tutorial](#output-binding-tutorial-2) - [Java functions](#java-functions) + - [Input Binding Tutorial](#input-binding-tutorial-3) + - [Output Binding Tutorial](#output-binding-tutorial-3) + - [Configuration](#configuration) + - [Trigger Binding Configuration](#trigger-binding-configuration) + - [Sql_Trigger_BatchSize](#sql_trigger_batchsize) + - [Sql_Trigger_PollingIntervalMs](#sql_trigger_pollingintervalms) + - [Sql_Trigger_MaxChangesPerWorker](#sql_trigger_maxchangesperworker) - [More Samples](#more-samples) - [Input Binding](#input-binding) - [Query String](#query-string) @@ -46,6 +61,15 @@ Azure SQL bindings for Azure Functions are supported for: - [Array](#array) - [Single Row](#single-row) - [Primary Key Special Cases](#primary-key-special-cases) + - [Identity Columns](#identity-columns) + - [Columns with Default Values](#columns-with-default-values) + - [Trigger Binding](#trigger-binding) + - [Change Tracking](#change-tracking) + - [Scaling](#scaling) + - [Internal State Tables](#internal-state-tables) + - [az_func.GlobalState](#az_funcglobalstate) + - [az_func.Leases_*](#az_funcleases_) + - [Trigger Samples](#trigger-samples) - [Known Issues](#known-issues) - [Telemetry](#telemetry) - [Trademarks](#trademarks) @@ -144,6 +168,7 @@ These steps can be done in the Terminal/CLI or with PowerShell. 3. Enable SQL bindings on the function app. More information can be found [in Microsoft Docs](https://docs.microsoft.com/azure/azure-functions/functions-bindings-azure-sql). **.NET:** Install the extension. + ```powershell dotnet add package Microsoft.Azure.WebJobs.Extensions.Sql --prerelease ``` @@ -242,7 +267,7 @@ Once you have your Function App you need to configure it for use with Azure SQL } ``` -1. You have setup your local environment and are now ready to create your first SQL bindings! Continue to the [input](#Input-Binding-Tutorial) and [output](#Output-Binding-Tutorial) binding tutorials, or refer to [More Samples](#More-Samples) for information on how to use the bindings and explore on your own. +1. You have setup your local environment and are now ready to create your first SQL bindings! Continue to the [input](#Input-Binding-Tutorial), [output](#Output-Binding-Tutorial) and [trigger](#trigger-binding-tutorial) binding tutorials, or refer to [More Samples](#More-Samples) for information on how to use the bindings and explore on your own. ## Tutorials @@ -342,6 +367,46 @@ Note: This tutorial requires that a SQL database is setup as shown in [Create a - Hit 'F5' to run your code. Click the link to upsert the output array values in your SQL table. Your upserted values should launch in the browser. - Congratulations! You have successfully created your first SQL output binding! Checkout [Output Binding](#Output-Binding) for more information on how to use it and explore on your own! +#### Trigger Binding Tutorial + +Note: This tutorial requires that a SQL database is setup as shown in [Create a SQL Server](#create-a-sql-server), and that you have the 'Employee.cs' file from the [Input Binding Tutorial](#input-binding-tutorial). + +- Create a new file with the following content: + + ```csharp + using System.Collections.Generic; + using Microsoft.Azure.WebJobs; + using Microsoft.Extensions.Logging; + using Microsoft.Azure.WebJobs.Extensions.Sql; + + namespace Company.Function + { + public static class EmployeeTrigger + { + [FunctionName("EmployeeTrigger")] + public static void Run( + [SqlTrigger("[dbo].[Employees]", ConnectionStringSetting = "SqlConnectionString")] + IReadOnlyList> changes, + ILogger logger) + { + foreach (SqlChange change in changes) + { + Employee employee = change.Item; + logger.LogInformation($"Change operation: {change.Operation}"); + logger.LogInformation($"EmployeeID: {employee.EmployeeId}, FirstName: {employee.FirstName}, LastName: {employee.LastName}, Company: {employee.Company}, Team: {employee.Team}"); + } + } + } + } + ``` + +- *Skip these steps if you have not completed the output binding tutorial.* + - Open your output binding file and modify some of the values. For example, change the value of Team column from 'Functions' to 'Azure SQL'. + - Hit 'F5' to run your code. Click the link of the HTTP trigger from the output binding tutorial. +- Update, insert, or delete rows in your SQL table while the function app is running and observe the function logs. +- You should see the new log messages in the Visual Studio Code terminal containing the values of row-columns after the update operation. +- Congratulations! You have successfully created your first SQL trigger binding! Checkout [Trigger Samples](#trigger-samples) for more information on how to use it and explore on your own! + ### JavaScript functions @@ -553,30 +618,26 @@ Note: This tutorial requires that a SQL database is setup as shown in [Create a commandType = "Text", connectionStringSetting = "SqlConnectionString") Employee[] employees) { - return request.createResponseBuilder(HttpStatus.OK).header("Content-Type", "application/json").body(employees).build(); } ``` *In the above, "select * from Employees" is the SQL script run by the input binding. The CommandType on the line below specifies whether the first line is a query or a stored procedure. On the next line, the ConnectionStringSetting specifies that the app setting that contains the SQL connection string used to connect to the database is "SqlConnectionString." For more information on this, see the [Input Binding](#Input-Binding) section* -- Add 'import com.microsoft.azure.functions.sql.annotation.SQLInput;' +- Add 'import com.microsoft.azure.functions.sql.annotation.SQLInput;' - Create a new file and call it 'Employee.java' - Paste the below in the file. These are the column names of our SQL table. ```java package com.function.Common; - public class Employee { private int EmployeeId; private String LastName; private String FirstName; private String Company; private String Team; - public Employee() { } - public Employee(int employeeId, String lastName, String firstName, String company, String team) { EmployeeId = employeeId; LastName = lastName; @@ -584,43 +645,33 @@ Note: This tutorial requires that a SQL database is setup as shown in [Create a Company = company; Team = team; } - public int getEmployeeId() { return EmployeeId; } - public void setEmployeeId(int employeeId) { this.EmployeeId = employeeId; } - public String getLastName() { return LastName; } - public void setLastName(String lastName) { this.LastName = lastName; } - public String getFirstName() { return FirstName; } - public void setFirstName(String firstName) { this.FirstName = firstName; } - public String getCompany() { return Company; } - public void setCompany(String company) { this.Company = company; } - public String getTeam() { return Team; } - public void setTeam(String team) { this.Team = team; } @@ -655,13 +706,11 @@ Note: This tutorial requires that a SQL database is setup as shown in [Create a commandText = "dbo.Employees", connectionStringSetting = "SqlConnectionString") OutputBinding output) { - output = new Employee[] { new Employee(1, "Hello", "World", "Microsoft", "Functions"), new Employee(2, "Hi", "SQLupdate", "Microsoft", "Functions") }; - return request.createResponseBuilder(HttpStatus.OK).header("Content-Type", "application/json").body(output).build(); } ``` @@ -671,6 +720,24 @@ Note: This tutorial requires that a SQL database is setup as shown in [Create a - Hit 'F5' to run your code. Click the link to upsert the output array values in your SQL table. Your upserted values should launch in the browser. - Congratulations! You have successfully created your first SQL output binding! Checkout [Output Binding](#Output-Binding) for more information on how to use it and explore on your own! +## Configuration + +This section goes over some of the configuration values you can use to customize the SQL bindings. See [How to Use Azure Function App Settings](https://learn.microsoft.com/azure/azure-functions/functions-how-to-use-azure-function-app-settings) to learn more. + +### Trigger Binding Configuration + +#### Sql_Trigger_BatchSize + +This controls the number of changes processed at once before being sent to the triggered function. + +#### Sql_Trigger_PollingIntervalMs + +This controls the delay in milliseconds between processing each batch of changes. + +#### Sql_Trigger_MaxChangesPerWorker + +This controls the upper limit on the number of pending changes in the user table that are allowed per application-worker. If the count of changes exceeds this limit, it may result in a scale out. The setting only applies for Azure Function Apps with runtime driven scaling enabled. See the [Scaling](#scaling) section for more information. + ## More Samples ### Input Binding @@ -945,11 +1012,106 @@ In the case where one of the primary key columns has a default value, there are 1. If the column with a default value is not included in the output object, then a straight insert is always performed with the other values. See [AddProductWithDefaultPK](./samples/samples-csharp/OutputBindingSamples/AddProductWithDefaultPK.cs) for an example. 2. If the column with a default value is included then a merge is performed similar to what happens when no default column is present. If there is a nullable column with a default value, then the provided column value in the output object will be upserted even if it is null. +### Trigger Binding + +> **NOTE:** Trigger binding support is only available for C# functions at present. + +#### Change Tracking + +The trigger binding utilizes SQL [change tracking](https://docs.microsoft.com/sql/relational-databases/track-changes/about-change-tracking-sql-server) functionality to monitor the user table for changes. As such, it is necessary to enable change tracking on the SQL database and the SQL table before using the trigger support. The change tracking can be enabled through the following two queries. + +1. Enabling change tracking on the SQL database: + + ```sql + ALTER DATABASE ['your database name'] + SET CHANGE_TRACKING = ON + (CHANGE_RETENTION = 2 DAYS, AUTO_CLEANUP = ON); + ``` + + The `CHANGE_RETENTION` option specifies the duration for which the changes are retained in the change tracking table. This may affect the trigger functionality. For example, if the user application is turned off for several days and then resumed, it will only be able to catch the changes that occurred in past two days with the above query. Hence, please update the value of `CHANGE_RETENTION` to suit your requirements. The `AUTO_CLEANUP` option is used to enable or disable the clean-up task that removes the stale data. Please refer to SQL Server documentation [here](https://docs.microsoft.com/sql/relational-databases/track-changes/enable-and-disable-change-tracking-sql-server#enable-change-tracking-for-a-database) for more information. + +1. Enabling change tracking on the SQL table: + + ```sql + ALTER TABLE dbo.Employees + ENABLE CHANGE_TRACKING; + ``` + + For more information, please refer to the documentation [here](https://docs.microsoft.com/sql/relational-databases/track-changes/enable-and-disable-change-tracking-sql-server#enable-change-tracking-for-a-table). The trigger needs to have read access on the table being monitored for changes as well as to the change tracking system tables. It also needs write access to an `az_func` schema within the database, where it will create additional leases tables to store the trigger states and leases. Each function trigger will thus have an associated change tracking table and leases table. + + > **NOTE:** The leases table contains all columns corresponding to the primary key from the user table and three additional columns named `_az_func_ChangeVersion`, `_az_func_AttemptCount` and `_az_func_LeaseExpirationTime`. If any of the primary key columns happen to have the same name, that will result in an error message listing any conflicts. In this case, the listed primary key columns must be renamed for the trigger to work. + +#### Scaling + +If your application containing functions with SQL trigger bindings is running as an Azure function app, it will be scaled automatically based on the amount of changes that are pending to be processed in the user table. As of today, we only support scaling of function apps running in Elastic Premium plan. To enable scaling, you will need to go the function app resource's page on Azure Portal, then to Configuration > 'Function runtime settings' and turn on 'Runtime Scale Monitoring'. For more information, check documentation on [Runtime Scaling](https://learn.microsoft.com/azure/azure-functions/event-driven-scaling#runtime-scaling). You can configure scaling parameters by going to 'Scale out (App Service plan)' setting on the function app's page. To understand various scale settings, please check the respective sections in [Azure Functions Premium plan](https://learn.microsoft.com/azure/azure-functions/functions-premium-plan?tabs=portal#eliminate-cold-starts)'s documentation. + +There are a couple of checks made to decide on whether the host application needs to be scaled in or out. The rationale behind these checks is to ensure that the count of pending changes per application-worker stays below a certain maximum limit, which is defaulted to 1000, while also ensuring that the number of workers running stays minimal. The scaling decision is made based on the latest count of the pending changes and whether the last 5 times we checked the count, we found it to be continuously increasing or decreasing. + +#### Internal State Tables + +The trigger functionality creates several tables to use for tracking the current state of the trigger. This allows state to be persisted across sessions and for multiple instances of a trigger binding to execute in parallel (for scaling purposes). + +In addition, a schema named `az_func` will be created that the tables will belong to. + +The login the trigger is configured to use must be given permissions to create these tables and schema. If not, then an error will be thrown and the trigger will fail to run. + +If the tables are deleted or modified, then unexpected behavior may occur. To reset the state of the triggers, first stop all currently running functions with trigger bindings and then either truncate or delete the tables. The next time a function with a trigger binding is started, it will recreate the tables as necessary. + +##### az_func.GlobalState + +This table stores information about each function being executed, what table that function is watching and what the [last sync state](https://learn.microsoft.com/sql/relational-databases/track-changes/work-with-change-tracking-sql-server) that has been processed. + +##### az_func.Leases_* + +A `Leases_*` table is created for every unique instance of a function and table. The full name will be in the format `Leases__` where `` is generated from the function ID and `` is the object ID of the table being tracked. Such as `Leases_7d12c06c6ddff24c_1845581613`. + +This table is used to ensure that all changes are processed and that no change is processed more than once. This table consists of two groups of columns: + + * A column for each column in the primary key of the target table - used to identify the row that it maps to in the target table + * A couple columns for tracking the state of each row. These are: + * `_az_func_ChangeVersion` for the change version of the row currently being processed + * `_az_func_AttemptCount` for tracking the number of times that a change has attempted to be processed to avoid getting stuck trying to process a change it's unable to handle + * `_az_func_LeaseExpirationTime` for tracking when the lease on this row for a particular instance is set to expire. This ensures that if an instance exits unexpectedly another instance will be able to pick up and process any changes it had leases for after the expiration time has passed. + +A row is created for every row in the target table that is modified. These are then cleaned up after the changes are processed for a set of changes corresponding to a change tracking sync version. + +#### Trigger Samples +The trigger binding takes two [arguments](https://github.com/Azure/azure-functions-sql-extension/blob/main/src/TriggerBinding/SqlTriggerAttribute.cs) + +- **TableName**: Passed as a constructor argument to the binding. Represents the name of the table to be monitored for changes. +- **ConnectionStringSetting**: Specifies the name of the app setting that contains the SQL connection string used to connect to a database. The connection string must follow the format specified [here](https://docs.microsoft.com/dotnet/api/microsoft.data.sqlclient.sqlconnection.connectionstring?view=sqlclient-dotnet-core-2.0). + +The trigger binding can bind to type `IReadOnlyList>`: + +- **IReadOnlyList>**: If there are multiple rows updated in the SQL table, the user function will get invoked with a batch of changes, where each element is a `SqlChange` object. Here `T` is a generic type-argument that can be substituted with a user-defined POCO, or Plain Old C# Object, representing the user table row. The POCO should therefore follow the schema of the queried table. See the [Query String](#query-string) section for an example of what the POCO should look like. The two properties of class `SqlChange` are `Item` of type `T` which represents the table row and `Operation` of type `SqlChangeOperation` which indicates the kind of row operation (insert, update, or delete) that triggered the user function. + +Note that for insert and update operations, the user function receives POCO object containing the latest values of table columns. For delete operation, only the properties corresponding to the primary keys of the row are populated. + +Any time when the changes happen to the "Products" table, the user function will be invoked with a batch of changes. The changes are processed sequentially, so if there are a large number of changes pending to be processed, the function will be passed a batch containing the earliest changes first. + +```csharp +[FunctionName("ProductsTrigger")] +public static void Run( + [SqlTrigger("Products", ConnectionStringSetting = "SqlConnectionString")] + IReadOnlyList> changes, + ILogger logger) +{ + foreach (SqlChange change in changes) + { + Product product = change.Item; + logger.LogInformation($"Change operation: {change.Operation}"); + logger.LogInformation($"ProductID: {product.ProductID}, Name: {product.Name}, Cost: {product.Cost}"); + } +} +``` + ## Known Issues - Output bindings against tables with columns of data types `NTEXT`, `TEXT`, or `IMAGE` are not supported and data upserts will fail. These types [will be removed](https://docs.microsoft.com/sql/t-sql/data-types/ntext-text-and-image-transact-sql) in a future version of SQL Server and are not compatible with the `OPENJSON` function used by this Azure Functions binding. - Input bindings against tables with columns of data types 'DATETIME', 'DATETIME2', or 'SMALLDATETIME' will assume that the values are in UTC format. +- Trigger bindings will exhibit undefined behavior if the SQL table schema gets modified while the user application is running, for example, if a column is added, renamed or deleted or if the primary key is modified or deleted. In such cases, restarting the application should help resolve any errors. + ## Telemetry This extension collect usage data in order to help us improve your experience. The data is anonymous and doesn't include any personal information. You can opt-out of telemetry by setting the `AZUREFUNCTIONS_SQLBINDINGS_TELEMETRY_OPTOUT` environment variable or the `AzureFunctionsSqlBindingsTelemetryOptOut` app setting (in your `*.settings.json` file) to '1', 'true' or 'yes'; diff --git a/performance/.editorconfig b/performance/.editorconfig new file mode 100644 index 000000000..77a834e7a --- /dev/null +++ b/performance/.editorconfig @@ -0,0 +1,10 @@ +# See https://github.com/dotnet/roslyn-analyzers/blob/main/.editorconfig for an example on different settings and how they're used + +[*.cs] + +# Disabled +dotnet_diagnostic.CA1309.severity = silent # Use ordinal StringComparison - this isn't important for tests and just adds clutter +dotnet_diagnostic.CA1305.severity = silent # Specify IFormatProvider - this isn't important for tests and just adds clutter +dotnet_diagnostic.CA1707.severity = silent # Identifiers should not contain underscores - this helps make test names more readable +dotnet_diagnostic.CA2201.severity = silent # Do not raise reserved exception types - tests can throw whatever they want +dotnet_diagnostic.CA1051.severity = silent # Do not declare visible instance fields - doesn't matter for tests \ No newline at end of file diff --git a/performance/SqlBindingBenchmarks.cs b/performance/SqlBindingBenchmarks.cs index b56563db3..9cceb2797 100644 --- a/performance/SqlBindingBenchmarks.cs +++ b/performance/SqlBindingBenchmarks.cs @@ -11,6 +11,11 @@ public static void Main() { BenchmarkRunner.Run(); BenchmarkRunner.Run(); + BenchmarkRunner.Run(); + BenchmarkRunner.Run(); + BenchmarkRunner.Run(); + BenchmarkRunner.Run(); + BenchmarkRunner.Run(); } } } \ No newline at end of file diff --git a/performance/SqlTriggerBindingPerformance.cs b/performance/SqlTriggerBindingPerformance.cs new file mode 100644 index 000000000..2c7413897 --- /dev/null +++ b/performance/SqlTriggerBindingPerformance.cs @@ -0,0 +1,38 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System.Threading.Tasks; +using Microsoft.Azure.WebJobs.Extensions.Sql.Samples.TriggerBindingSamples; +using Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Common; +using BenchmarkDotNet.Attributes; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql.Performance +{ + [MemoryDiagnoser] + public class SqlTriggerBindingPerformance : SqlTriggerBindingPerformanceTestBase + { + [GlobalSetup] + public void GlobalSetup() + { + this.SetChangeTrackingForTable("Products", true); + this.StartFunctionHost(nameof(ProductsTrigger), SupportedLanguages.CSharp); + } + + [Benchmark] + [Arguments(1)] + [Arguments(10)] + [Arguments(100)] + [Arguments(1000)] + public async Task ProductsTriggerTest(int count) + { + await this.WaitForProductChanges( + 1, + count, + SqlChangeOperation.Insert, + () => { this.InsertProducts(1, count); return Task.CompletedTask; }, + id => $"Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(1, count)); + } + } +} \ No newline at end of file diff --git a/performance/SqlTriggerBindingPerformanceTestBase.cs b/performance/SqlTriggerBindingPerformanceTestBase.cs new file mode 100644 index 000000000..ee6662c1e --- /dev/null +++ b/performance/SqlTriggerBindingPerformanceTestBase.cs @@ -0,0 +1,40 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Integration; +using BenchmarkDotNet.Attributes; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql.Performance +{ + public class SqlTriggerBindingPerformanceTestBase : SqlTriggerBindingIntegrationTests + { + [IterationCleanup] + public void IterationCleanup() + { + // Delete all rows in Products table after each iteration so we start fresh each time + this.ExecuteNonQuery("TRUNCATE TABLE Products"); + // Clear the leases table, otherwise we may end up getting blocked by leases from a previous run + this.ExecuteNonQuery(@"DECLARE @cmd varchar(100) + DECLARE cmds CURSOR FOR + SELECT 'TRUNCATE TABLE az_func.' + Name + '' + FROM sys.tables + WHERE Name LIKE 'Leases_%' + + OPEN cmds + WHILE 1 = 1 + BEGIN + FETCH cmds INTO @cmd + IF @@fetch_status != 0 BREAK + EXEC(@cmd) + END + CLOSE cmds; + DEALLOCATE cmds"); + } + + [GlobalCleanup] + public void GlobalCleanup() + { + this.Dispose(); + } + } +} \ No newline at end of file diff --git a/performance/SqlTriggerBindingPerformance_Parallelization.cs b/performance/SqlTriggerBindingPerformance_Parallelization.cs new file mode 100644 index 000000000..4b46e8f60 --- /dev/null +++ b/performance/SqlTriggerBindingPerformance_Parallelization.cs @@ -0,0 +1,67 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System.Threading.Tasks; +using Microsoft.Azure.WebJobs.Extensions.Sql.Samples.TriggerBindingSamples; +using Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Common; +using BenchmarkDotNet.Attributes; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql.Performance +{ + [MemoryDiagnoser] + public class SqlTriggerBindingPerformance_Parallelization : SqlTriggerBindingPerformanceTestBase + { + [Params(2, 5)] + public int HostCount; + + [GlobalSetup] + public void GlobalSetup() + { + this.SetChangeTrackingForTable("Products", true); + for (int i = 0; i < this.HostCount; ++i) + { + this.StartFunctionHost(nameof(ProductsTrigger), SupportedLanguages.CSharp); + } + } + + [Benchmark] + public async Task MultiHost() + { + int firstId = 1; + int lastId = 90; + await this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Insert, + () => { this.InsertProducts(firstId, lastId); return Task.CompletedTask; }, + id => $"Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(firstId, lastId)); + + firstId = 1; + lastId = 60; + // All table columns (not just the columns that were updated) would be returned for update operation. + await this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Update, + () => { this.UpdateProducts(firstId, lastId); return Task.CompletedTask; }, + id => $"Updated Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(firstId, lastId)); + + firstId = 31; + lastId = 90; + // The properties corresponding to non-primary key columns would be set to the C# type's default values + // (null and 0) for delete operation. + await this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Delete, + () => { this.DeleteProducts(firstId, lastId); return Task.CompletedTask; }, + _ => null, + _ => 0, + this.GetBatchProcessingTimeout(firstId, lastId)); + } + } +} \ No newline at end of file diff --git a/performance/SqlTriggerPerformance_BatchOverride.cs b/performance/SqlTriggerPerformance_BatchOverride.cs new file mode 100644 index 000000000..803774d29 --- /dev/null +++ b/performance/SqlTriggerPerformance_BatchOverride.cs @@ -0,0 +1,49 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System.Threading.Tasks; +using Microsoft.Azure.WebJobs.Extensions.Sql.Samples.TriggerBindingSamples; +using Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Common; +using BenchmarkDotNet.Attributes; +using System.Collections.Generic; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql.Performance +{ + [MemoryDiagnoser] + public class SqlTriggerBindingPerformance_BatchOverride : SqlTriggerBindingPerformanceTestBase + { + + [Params(100, 1000)] + public int BatchSize; + + [GlobalSetup] + public void GlobalSetup() + { + this.SetChangeTrackingForTable("Products", true); + this.StartFunctionHost( + nameof(ProductsTrigger), + SupportedLanguages.CSharp, + environmentVariables: new Dictionary() { + { "Sql_Trigger_BatchSize", this.BatchSize.ToString() } + }); + } + + [Benchmark] + [Arguments(0.1)] + [Arguments(0.5)] + [Arguments(1)] + [Arguments(5)] + public async Task Run(double numBatches) + { + int count = (int)(numBatches * this.BatchSize); + await this.WaitForProductChanges( + 1, + count, + SqlChangeOperation.Insert, + () => { this.InsertProducts(1, count); return Task.CompletedTask; }, + id => $"Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(1, count, batchSize: this.BatchSize)); + } + } +} \ No newline at end of file diff --git a/performance/SqlTriggerPerformance_Overrides.cs b/performance/SqlTriggerPerformance_Overrides.cs new file mode 100644 index 000000000..6b7faef62 --- /dev/null +++ b/performance/SqlTriggerPerformance_Overrides.cs @@ -0,0 +1,53 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System.Threading.Tasks; +using Microsoft.Azure.WebJobs.Extensions.Sql.Samples.TriggerBindingSamples; +using Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Common; +using BenchmarkDotNet.Attributes; +using System.Collections.Generic; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql.Performance +{ + [MemoryDiagnoser] + public class SqlTriggerPerformance_Overrides : SqlTriggerBindingPerformanceTestBase + { + [Params(1, 10, 100, 500)] + public int PollingIntervalMs; + + [Params(500, 1000, 2000)] + public int BatchSize; + + [GlobalSetup] + public void GlobalSetup() + { + this.SetChangeTrackingForTable("Products", true); + this.StartFunctionHost( + nameof(ProductsTrigger), + SupportedLanguages.CSharp, + environmentVariables: new Dictionary() { + { "Sql_Trigger_BatchSize", this.BatchSize.ToString() }, + { "Sql_Trigger_PollingIntervalMs", this.PollingIntervalMs.ToString() } + }); + } + + [Benchmark] + [Arguments(0.1)] + [Arguments(0.5)] + [Arguments(1)] + [Arguments(5)] + [Arguments(10)] + public async Task Run(double numBatches) + { + int count = (int)(numBatches * this.BatchSize); + await this.WaitForProductChanges( + 1, + count, + SqlChangeOperation.Insert, + () => { this.InsertProducts(1, count); return Task.CompletedTask; }, + id => $"Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(1, count, batchSize: this.BatchSize)); + } + } +} \ No newline at end of file diff --git a/performance/SqlTriggerPerformance_PollingIntervalOverride.cs b/performance/SqlTriggerPerformance_PollingIntervalOverride.cs new file mode 100644 index 000000000..2d0bc0b68 --- /dev/null +++ b/performance/SqlTriggerPerformance_PollingIntervalOverride.cs @@ -0,0 +1,44 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System.Threading.Tasks; +using Microsoft.Azure.WebJobs.Extensions.Sql.Samples.TriggerBindingSamples; +using Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Common; +using BenchmarkDotNet.Attributes; +using System.Collections.Generic; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql.Performance +{ + [MemoryDiagnoser] + public class SqlTriggerBindingPerformance_PollingIntervalOverride : SqlTriggerBindingPerformanceTestBase + { + [Params(1, 10, 100, 500, 2000)] + public int PollingIntervalMs; + + [GlobalSetup] + public void GlobalSetup() + { + this.SetChangeTrackingForTable("Products", true); + this.StartFunctionHost( + nameof(ProductsTrigger), + SupportedLanguages.CSharp, + environmentVariables: new Dictionary() { + { "Sql_Trigger_PollingIntervalMs", this.PollingIntervalMs.ToString() } + }); + } + + [Benchmark] + public async Task Run() + { + int count = SqlTableChangeMonitor.DefaultBatchSize * 2; + await this.WaitForProductChanges( + 1, + count, + SqlChangeOperation.Insert, + () => { this.InsertProducts(1, count); return Task.CompletedTask; }, + id => $"Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(1, count, pollingIntervalMs: this.PollingIntervalMs)); + } + } +} \ No newline at end of file diff --git a/samples/samples-csharp/TriggerBindingSamples/ProductsTrigger.cs b/samples/samples-csharp/TriggerBindingSamples/ProductsTrigger.cs new file mode 100644 index 000000000..2a143678f --- /dev/null +++ b/samples/samples-csharp/TriggerBindingSamples/ProductsTrigger.cs @@ -0,0 +1,23 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System.Collections.Generic; +using Microsoft.Azure.WebJobs.Extensions.Sql.Samples.Common; +using Microsoft.Extensions.Logging; +using Newtonsoft.Json; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql.Samples.TriggerBindingSamples +{ + public static class ProductsTrigger + { + [FunctionName(nameof(ProductsTrigger))] + public static void Run( + [SqlTrigger("[dbo].[Products]", ConnectionStringSetting = "SqlConnectionString")] + IReadOnlyList> changes, + ILogger logger) + { + // The output is used to inspect the trigger binding parameter in test methods. + logger.LogInformation("SQL Changes: " + JsonConvert.SerializeObject(changes)); + } + } +} diff --git a/src/Microsoft.Azure.WebJobs.Extensions.Sql.csproj b/src/Microsoft.Azure.WebJobs.Extensions.Sql.csproj index e7dc1d6b8..6b643b84a 100644 --- a/src/Microsoft.Azure.WebJobs.Extensions.Sql.csproj +++ b/src/Microsoft.Azure.WebJobs.Extensions.Sql.csproj @@ -37,6 +37,7 @@ + diff --git a/src/SqlBindingConfigProvider.cs b/src/SqlBindingConfigProvider.cs index 217c966f5..f4af37a95 100644 --- a/src/SqlBindingConfigProvider.cs +++ b/src/SqlBindingConfigProvider.cs @@ -8,6 +8,7 @@ using static Microsoft.Azure.WebJobs.Extensions.Sql.Telemetry.Telemetry; using Microsoft.Azure.WebJobs.Host.Bindings; using Microsoft.Azure.WebJobs.Host.Config; +using Microsoft.Azure.WebJobs.Host.Executors; using Microsoft.Extensions.Configuration; using Microsoft.Extensions.Logging; using Microsoft.Azure.WebJobs.Logging; @@ -21,6 +22,7 @@ namespace Microsoft.Azure.WebJobs.Extensions.Sql internal class SqlBindingConfigProvider : IExtensionConfigProvider { private readonly IConfiguration _configuration; + private readonly IHostIdProvider _hostIdProvider; private readonly ILoggerFactory _loggerFactory; /// @@ -29,9 +31,10 @@ internal class SqlBindingConfigProvider : IExtensionConfigProvider /// /// Thrown if either parameter is null /// - public SqlBindingConfigProvider(IConfiguration configuration, ILoggerFactory loggerFactory) + public SqlBindingConfigProvider(IConfiguration configuration, IHostIdProvider hostIdProvider, ILoggerFactory loggerFactory) { this._configuration = configuration ?? throw new ArgumentNullException(nameof(configuration)); + this._hostIdProvider = hostIdProvider ?? throw new ArgumentNullException(nameof(hostIdProvider)); this._loggerFactory = loggerFactory ?? throw new ArgumentNullException(nameof(loggerFactory)); } @@ -57,6 +60,9 @@ public void Initialize(ExtensionConfigContext context) inputOutputRule.BindToInput(typeof(SqlGenericsConverter), this._configuration, logger); inputOutputRule.BindToCollector(typeof(SqlAsyncCollectorBuilder<>), this._configuration, logger); inputOutputRule.BindToInput(typeof(SqlGenericsConverter<>), this._configuration, logger); + + FluentBindingRule triggerRule = context.AddBindingRule(); + triggerRule.BindToTrigger(new SqlTriggerBindingProvider(this._configuration, this._hostIdProvider, this._loggerFactory)); } } diff --git a/src/Telemetry/Telemetry.cs b/src/Telemetry/Telemetry.cs index 1961c5ab3..961c1b8ec 100644 --- a/src/Telemetry/Telemetry.cs +++ b/src/Telemetry/Telemetry.cs @@ -320,18 +320,34 @@ public enum ConvertType /// public enum TelemetryEventName { + AcquireLeaseEnd, + AcquireLeaseStart, AddAsync, - Create, Convert, + Create, Error, FlushAsync, GetCaseSensitivity, + GetChangesEnd, + GetChangesStart, GetColumnDefinitions, GetPrimaryKeys, + GetScaleStatus, GetTableInfoEnd, GetTableInfoStart, + ReleaseLeasesEnd, + ReleaseLeasesStart, + RenewLeasesEnd, + RenewLeasesStart, + StartListenerEnd, + StartListenerStart, + StopListenerEnd, + StopListenerStart, TableInfoCacheHit, TableInfoCacheMiss, + TriggerFunctionEnd, + TriggerFunctionStart, + TriggerMonitorStart, UpsertEnd, UpsertStart, } @@ -341,13 +357,21 @@ public enum TelemetryEventName /// public enum TelemetryPropertyName { + ErrorCode, ErrorName, ExceptionType, HasIdentityColumn, + HasConfiguredBatchSize, + HasConfiguredMaxChangesPerWorker, + HasConfiguredPollingInterval, + LeasesTableName, QueryType, + ScaleRecommendation, ServerVersion, + TriggerMetrics, Type, - ErrorCode + UserFunctionId, + WorkerCount, } /// @@ -355,13 +379,28 @@ public enum TelemetryPropertyName /// public enum TelemetryMeasureName { + AcquireLeasesDurationMs, BatchCount, + BatchSize, CommandDurationMs, + CreatedSchemaDurationMs, + CreateGlobalStateTableDurationMs, + CreateLeasesTableDurationMs, DurationMs, GetCaseSensitivityDurationMs, + GetChangesDurationMs, GetColumnDefinitionsDurationMs, GetPrimaryKeysDurationMs, - TransactionDurationMs + GetUnprocessedChangesDurationMs, + InsertGlobalStateTableRowDurationMs, + MaxChangesPerWorker, + PollingIntervalMs, + ReleaseLeasesDurationMs, + RetryAttemptNumber, + SetLastSyncVersionDurationMs, + TransactionDurationMs, + UnprocessedChangeCount, + UpdateLastSyncVersionDurationMs, } /// @@ -369,15 +408,31 @@ public enum TelemetryMeasureName /// public enum TelemetryErrorName { + ConsumeChangesLoop, Convert, + CreateGlobalStateTable, + CreateLeasesTable, + CreateSchema, FlushAsync, GetCaseSensitivity, + GetChanges, + GetChangesRollback, GetColumnDefinitions, GetColumnDefinitionsTableDoesNotExist, GetPrimaryKeys, - NoPrimaryKeys, + GetScaleStatus, + GetUnprocessedChangeCount, + InvalidConfigurationValue, MissingPrimaryKeys, + NoPrimaryKeys, + ProcessChanges, PropsNotExistOnTable, + ReleaseLeases, + ReleaseLeasesNoRetriesLeft, + ReleaseLeasesRollback, + RenewLeases, + RenewLeasesLoop, + StartListener, Upsert, UpsertRollback, } diff --git a/src/TriggerBinding/SqlChange.cs b/src/TriggerBinding/SqlChange.cs new file mode 100644 index 000000000..61fa53564 --- /dev/null +++ b/src/TriggerBinding/SqlChange.cs @@ -0,0 +1,45 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +namespace Microsoft.Azure.WebJobs.Extensions.Sql +{ + /// + /// Represents the changed row in the user table. + /// + /// POCO class representing the row in the user table + public sealed class SqlChange + { + /// + /// Initializes a new instance of the class. + /// + /// Change operation + /// POCO representing the row in the user table on which the change operation took place + public SqlChange(SqlChangeOperation operation, T item) + { + this.Operation = operation; + this.Item = item; + } + + /// + /// Change operation (insert, update, or delete). + /// + public SqlChangeOperation Operation { get; } + + /// + /// POCO representing the row in the user table on which the change operation took place. If the change + /// operation is , then only the properties corresponding to the primary + /// keys will be populated. + /// + public T Item { get; } + } + + /// + /// Represents the type of change operation in the table row. + /// + public enum SqlChangeOperation + { + Insert, + Update, + Delete + } +} \ No newline at end of file diff --git a/src/TriggerBinding/SqlTableChangeMonitor.cs b/src/TriggerBinding/SqlTableChangeMonitor.cs new file mode 100644 index 000000000..4bd2dab74 --- /dev/null +++ b/src/TriggerBinding/SqlTableChangeMonitor.cs @@ -0,0 +1,1006 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System; +using System.Collections.Generic; +using System.Diagnostics; +using System.Globalization; +using System.IO; +using System.Linq; +using System.Text; +using System.Threading; +using System.Threading.Tasks; +using Microsoft.Azure.WebJobs.Extensions.Sql.Telemetry; +using static Microsoft.Azure.WebJobs.Extensions.Sql.Telemetry.Telemetry; +using static Microsoft.Azure.WebJobs.Extensions.Sql.SqlTriggerConstants; +using Microsoft.Azure.WebJobs.Host.Executors; +using Microsoft.Data.SqlClient; +using Microsoft.Extensions.Logging; +using Newtonsoft.Json; +using Microsoft.Extensions.Configuration; +using System.Data; +using MoreLinq; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql +{ + /// + /// Watches for changes in the user table, invokes user function if changes are found, and manages leases. + /// + /// POCO class representing the row in the user table + internal sealed class SqlTableChangeMonitor : IDisposable + { + #region Constants + /// + /// The maximum number of times we'll attempt to process a change before giving up + /// + private const int MaxChangeProcessAttemptCount = 5; + /// + /// The maximum number of times that we'll attempt to renew a lease be + /// + /// + /// Leases are held for approximately (LeaseRenewalIntervalInSeconds * MaxLeaseRenewalCount) seconds. It is + // required to have at least one of (LeaseIntervalInSeconds / LeaseRenewalIntervalInSeconds) attempts to + // renew the lease succeed to prevent it from expiring. + // + private const int MaxLeaseRenewalCount = 10; + private const int LeaseIntervalInSeconds = 60; + private const int LeaseRenewalIntervalInSeconds = 15; + private const int MaxRetryReleaseLeases = 3; + + public const int DefaultBatchSize = 100; + public const int DefaultPollingIntervalMs = 1000; + #endregion Constants + + private readonly string _connectionString; + private readonly int _userTableId; + private readonly SqlObject _userTable; + private readonly string _userFunctionId; + private readonly string _leasesTableName; + private readonly IReadOnlyList _userTableColumns; + private readonly IReadOnlyList<(string name, string type)> _primaryKeyColumns; + private readonly IReadOnlyList _rowMatchConditions; + private readonly ITriggeredFunctionExecutor _executor; + private readonly ILogger _logger; + /// + /// Number of changes to process in each iteration of the loop + /// + private readonly int _batchSize = DefaultBatchSize; + /// + /// Delay in ms between processing each batch of changes + /// + private readonly int _pollingIntervalInMs = DefaultPollingIntervalMs; + + private readonly CancellationTokenSource _cancellationTokenSourceCheckForChanges = new CancellationTokenSource(); + private readonly CancellationTokenSource _cancellationTokenSourceRenewLeases = new CancellationTokenSource(); + private CancellationTokenSource _cancellationTokenSourceExecutor = new CancellationTokenSource(); + + // The semaphore gets used by lease-renewal loop to ensure that '_state' stays set to 'ProcessingChanges' while + // the leases are being renewed. The change-consumption loop requires to wait for the semaphore before modifying + // the value of '_state' back to 'CheckingForChanges'. Since the field '_rows' is only updated if the value of + // '_state' is set to 'CheckingForChanges', this guarantees that '_rows' will stay same while it is being + // iterated over inside the lease-renewal loop. + private readonly SemaphoreSlim _rowsLock = new SemaphoreSlim(1, 1); + + private readonly IDictionary _telemetryProps; + + private IReadOnlyList> _rows = new List>(); + private int _leaseRenewalCount = 0; + private State _state = State.CheckingForChanges; + + /// + /// Initializes a new instance of the > class. + /// + /// SQL connection string used to connect to user database + /// SQL object ID of the user table + /// instance created with user table name + /// Unique identifier for the user function + /// Name of the leases table + /// List of all column names in the user table + /// List of primary key column names in the user table + /// Defines contract for triggering user function + /// Facilitates logging of messages + /// Provides configuration values + /// Properties passed in telemetry events + public SqlTableChangeMonitor( + string connectionString, + int userTableId, + SqlObject userTable, + string userFunctionId, + string leasesTableName, + IReadOnlyList userTableColumns, + IReadOnlyList<(string name, string type)> primaryKeyColumns, + ITriggeredFunctionExecutor executor, + ILogger logger, + IConfiguration configuration, + IDictionary telemetryProps) + { + this._connectionString = !string.IsNullOrEmpty(connectionString) ? connectionString : throw new ArgumentNullException(nameof(connectionString)); + this._userTable = !string.IsNullOrEmpty(userTable?.FullName) ? userTable : throw new ArgumentNullException(nameof(userTable)); + this._userFunctionId = !string.IsNullOrEmpty(userFunctionId) ? userFunctionId : throw new ArgumentNullException(nameof(userFunctionId)); + this._leasesTableName = !string.IsNullOrEmpty(leasesTableName) ? leasesTableName : throw new ArgumentNullException(nameof(leasesTableName)); + this._userTableColumns = userTableColumns ?? throw new ArgumentNullException(nameof(userTableColumns)); + this._primaryKeyColumns = primaryKeyColumns ?? throw new ArgumentNullException(nameof(primaryKeyColumns)); + this._executor = executor ?? throw new ArgumentNullException(nameof(executor)); + this._logger = logger ?? throw new ArgumentNullException(nameof(logger)); + + this._userTableId = userTableId; + this._telemetryProps = telemetryProps ?? new Dictionary(); + + // Check if there's config settings to override the default batch size/polling interval values + int? configuredBatchSize = configuration.GetValue(ConfigKey_SqlTrigger_BatchSize); + int? configuredPollingInterval = configuration.GetValue(ConfigKey_SqlTrigger_PollingInterval); + this._batchSize = configuredBatchSize ?? this._batchSize; + if (this._batchSize <= 0) + { + throw new InvalidOperationException($"Invalid value for configuration setting '{ConfigKey_SqlTrigger_BatchSize}'. Ensure that the value is a positive integer."); + } + this._pollingIntervalInMs = configuredPollingInterval ?? this._pollingIntervalInMs; + if (this._pollingIntervalInMs <= 0) + { + throw new InvalidOperationException($"Invalid value for configuration setting '{ConfigKey_SqlTrigger_PollingInterval}'. Ensure that the value is a positive integer."); + } + TelemetryInstance.TrackEvent( + TelemetryEventName.TriggerMonitorStart, + new Dictionary(telemetryProps) { + { TelemetryPropertyName.HasConfiguredBatchSize, (configuredBatchSize != null).ToString() }, + { TelemetryPropertyName.HasConfiguredPollingInterval, (configuredPollingInterval != null).ToString() }, + }, + new Dictionary() { + { TelemetryMeasureName.BatchSize, this._batchSize }, + { TelemetryMeasureName.PollingIntervalMs, this._pollingIntervalInMs } + } + ); + + // Prep search-conditions that will be used besides WHERE clause to match table rows. + this._rowMatchConditions = Enumerable.Range(0, this._batchSize) + .Select(rowIndex => string.Join(" AND ", this._primaryKeyColumns.Select((col, colIndex) => $"{col.name.AsBracketQuotedString()} = @{rowIndex}_{colIndex}"))) + .ToList(); + +#pragma warning disable CS4014 // Queue the below tasks and exit. Do not wait for their completion. + _ = Task.Run(() => + { + this.RunChangeConsumptionLoopAsync(); + this.RunLeaseRenewalLoopAsync(); + }); +#pragma warning restore CS4014 + } + + public void Dispose() + { + // When the CheckForChanges loop is finished, it will cancel the lease renewal loop. + this._cancellationTokenSourceCheckForChanges.Cancel(); + } + + public async Task GetUnprocessedChangeCountAsync() + { + long unprocessedChangeCount = 0L; + + try + { + long getUnprocessedChangesDurationMs = 0L; + + using (var connection = new SqlConnection(this._connectionString)) + { + this._logger.LogDebugWithThreadId("BEGIN OpenGetUnprocessedChangesConnection"); + await connection.OpenAsync(); + this._logger.LogDebugWithThreadId("END OpenGetUnprocessedChangesConnection"); + + using (SqlCommand getUnprocessedChangesCommand = this.BuildGetUnprocessedChangesCommand(connection)) + { + this._logger.LogDebugWithThreadId($"BEGIN GetUnprocessedChangeCount Query={getUnprocessedChangesCommand.CommandText}"); + var commandSw = Stopwatch.StartNew(); + unprocessedChangeCount = (long)await getUnprocessedChangesCommand.ExecuteScalarAsync(); + getUnprocessedChangesDurationMs = commandSw.ElapsedMilliseconds; + } + + this._logger.LogDebugWithThreadId($"END GetUnprocessedChangeCount Duration={getUnprocessedChangesDurationMs}ms Count={unprocessedChangeCount}"); + } + + var measures = new Dictionary + { + [TelemetryMeasureName.GetUnprocessedChangesDurationMs] = getUnprocessedChangesDurationMs, + [TelemetryMeasureName.UnprocessedChangeCount] = unprocessedChangeCount, + }; + } + catch (Exception ex) + { + this._logger.LogError($"Failed to query count of unprocessed changes for table '{this._userTable.FullName}' due to exception: {ex.GetType()}. Exception message: {ex.Message}"); + TelemetryInstance.TrackException(TelemetryErrorName.GetUnprocessedChangeCount, ex, this._telemetryProps); + } + + return unprocessedChangeCount; + } + + /// + /// Executed once every period. If the state of the change monitor is + /// , then the method query the change/leases tables for changes on the + /// user's table. If any are found, the state of the change monitor is transitioned to + /// and the user's function is executed with the found changes. If the + /// execution is successful, the leases on "_rows" are released and the state transitions to + /// once again. + /// + private async Task RunChangeConsumptionLoopAsync() + { + this._logger.LogInformationWithThreadId($"Starting change consumption loop. BatchSize: {this._batchSize} PollingIntervalMs: {this._pollingIntervalInMs}"); + + try + { + CancellationToken token = this._cancellationTokenSourceCheckForChanges.Token; + + using (var connection = new SqlConnection(this._connectionString)) + { + this._logger.LogDebugWithThreadId("BEGIN OpenChangeConsumptionConnection"); + await connection.OpenAsync(token); + this._logger.LogDebugWithThreadId("END OpenChangeConsumptionConnection"); + + // Check for cancellation request only after a cycle of checking and processing of changes completes. + while (!token.IsCancellationRequested) + { + this._logger.LogDebugWithThreadId($"BEGIN CheckingForChanges State={this._state}"); + if (this._state == State.CheckingForChanges) + { + await this.GetTableChangesAsync(connection, token); + await this.ProcessTableChangesAsync(connection, token); + } + this._logger.LogDebugWithThreadId("END CheckingForChanges"); + this._logger.LogDebugWithThreadId($"Delaying for {this._pollingIntervalInMs}ms"); + await Task.Delay(TimeSpan.FromMilliseconds(this._pollingIntervalInMs), token); + } + } + } + catch (Exception e) + { + // Only want to log the exception if it wasn't caused by StopAsync being called, since Task.Delay + // throws an exception if it's cancelled. + if (e.GetType() != typeof(TaskCanceledException)) + { + this._logger.LogError($"Exiting change consumption loop due to exception: {e.GetType()}. Exception message: {e.Message}"); + TelemetryInstance.TrackException(TelemetryErrorName.ConsumeChangesLoop, e, this._telemetryProps); + } + } + finally + { + // If this thread exits due to any reason, then the lease renewal thread should exit as well. Otherwise, + // it will keep looping perpetually. + this._cancellationTokenSourceRenewLeases.Cancel(); + this._cancellationTokenSourceCheckForChanges.Dispose(); + this._cancellationTokenSourceExecutor.Dispose(); + } + } + + /// + /// Queries the change/leases tables to check for new changes on the user's table. If any are found, stores the + /// change along with the corresponding data from the user table in "_rows". + /// + private async Task GetTableChangesAsync(SqlConnection connection, CancellationToken token) + { + TelemetryInstance.TrackEvent(TelemetryEventName.GetChangesStart, this._telemetryProps); + this._logger.LogDebugWithThreadId("BEGIN GetTableChanges"); + try + { + var transactionSw = Stopwatch.StartNew(); + long setLastSyncVersionDurationMs = 0L, getChangesDurationMs = 0L, acquireLeasesDurationMs = 0L; + + using (SqlTransaction transaction = connection.BeginTransaction(IsolationLevel.RepeatableRead)) + { + try + { + // Update the version number stored in the global state table if necessary before using it. + using (SqlCommand updateTablesPreInvocationCommand = this.BuildUpdateTablesPreInvocation(connection, transaction)) + { + this._logger.LogDebugWithThreadId($"BEGIN UpdateTablesPreInvocation Query={updateTablesPreInvocationCommand.CommandText}"); + var commandSw = Stopwatch.StartNew(); + await updateTablesPreInvocationCommand.ExecuteNonQueryAsync(token); + setLastSyncVersionDurationMs = commandSw.ElapsedMilliseconds; + } + this._logger.LogDebugWithThreadId($"END UpdateTablesPreInvocation Duration={setLastSyncVersionDurationMs}ms"); + + var rows = new List>(); + + // Use the version number to query for new changes. + using (SqlCommand getChangesCommand = this.BuildGetChangesCommand(connection, transaction)) + { + this._logger.LogDebugWithThreadId($"BEGIN GetChanges Query={getChangesCommand.CommandText}"); + var commandSw = Stopwatch.StartNew(); + + using (SqlDataReader reader = await getChangesCommand.ExecuteReaderAsync(token)) + { + while (await reader.ReadAsync(token)) + { + rows.Add(SqlBindingUtilities.BuildDictionaryFromSqlRow(reader)); + } + } + + getChangesDurationMs = commandSw.ElapsedMilliseconds; + } + this._logger.LogDebugWithThreadId($"END GetChanges Duration={getChangesDurationMs}ms ChangedRows={rows.Count}"); + + // If changes were found, acquire leases on them. + if (rows.Count > 0) + { + using (SqlCommand acquireLeasesCommand = this.BuildAcquireLeasesCommand(connection, transaction, rows)) + { + this._logger.LogDebugWithThreadId($"BEGIN AcquireLeases Query={acquireLeasesCommand.CommandText}"); + var commandSw = Stopwatch.StartNew(); + await acquireLeasesCommand.ExecuteNonQueryAsync(token); + acquireLeasesDurationMs = commandSw.ElapsedMilliseconds; + } + this._logger.LogDebugWithThreadId($"END AcquireLeases Duration={acquireLeasesDurationMs}ms"); + } + + transaction.Commit(); + + // Set the rows for processing, now since the leases are acquired. + this._rows = rows; + + var measures = new Dictionary + { + [TelemetryMeasureName.SetLastSyncVersionDurationMs] = setLastSyncVersionDurationMs, + [TelemetryMeasureName.GetChangesDurationMs] = getChangesDurationMs, + [TelemetryMeasureName.AcquireLeasesDurationMs] = acquireLeasesDurationMs, + [TelemetryMeasureName.TransactionDurationMs] = transactionSw.ElapsedMilliseconds, + [TelemetryMeasureName.BatchCount] = this._rows.Count, + }; + + TelemetryInstance.TrackEvent(TelemetryEventName.GetChangesEnd, this._telemetryProps, measures); + } + catch (Exception ex) + { + this._logger.LogError($"Failed to query list of changes for table '{this._userTable.FullName}' due to exception: {ex.GetType()}. Exception message: {ex.Message}"); + TelemetryInstance.TrackException(TelemetryErrorName.GetChanges, ex, this._telemetryProps); + + try + { + transaction.Rollback(); + } + catch (Exception ex2) + { + this._logger.LogError($"Failed to rollback transaction due to exception: {ex2.GetType()}. Exception message: {ex2.Message}"); + TelemetryInstance.TrackException(TelemetryErrorName.GetChangesRollback, ex2, this._telemetryProps); + } + } + } + } + catch (Exception e) + { + // If there's an exception in any part of the process, we want to clear all of our data in memory and + // retry checking for changes again. + this._rows = new List>(); + this._logger.LogError($"Failed to check for changes in table '{this._userTable.FullName}' due to exception: {e.GetType()}. Exception message: {e.Message}"); + TelemetryInstance.TrackException(TelemetryErrorName.GetChanges, e, this._telemetryProps); + } + this._logger.LogDebugWithThreadId("END GetTableChanges"); + } + + private async Task ProcessTableChangesAsync(SqlConnection connection, CancellationToken token) + { + this._logger.LogDebugWithThreadId("BEGIN ProcessTableChanges"); + if (this._rows.Count > 0) + { + this._state = State.ProcessingChanges; + IReadOnlyList> changes = null; + + try + { + changes = this.ProcessChanges(); + } + catch (Exception e) + { + // Either there's a bug or we're in a bad state so not much we can do here. We'll try clearing + // our state and retry getting the changes from the top again in case something broke while + // fetching the changes. + // It doesn't make sense to retry processing the changes immediately since this isn't a connection-based issue. + // We could probably send up the changes we were able to process and just skip the ones we couldn't, but given + // that this is not a case we expect would happen during normal execution we'll err on the side of caution for + // now and just retry getting the whole set of changes. + this._logger.LogError($"Failed to compose trigger parameter value for table: '{this._userTable.FullName} due to exception: {e.GetType()}. Exception message: {e.Message}"); + TelemetryInstance.TrackException(TelemetryErrorName.ProcessChanges, e, this._telemetryProps); + await this.ClearRowsAsync(); + } + + if (changes != null) + { + var input = new TriggeredFunctionData() { TriggerValue = changes }; + + TelemetryInstance.TrackEvent(TelemetryEventName.TriggerFunctionStart, this._telemetryProps); + this._logger.LogDebugWithThreadId("Executing triggered function"); + var stopwatch = Stopwatch.StartNew(); + + FunctionResult result = await this._executor.TryExecuteAsync(input, this._cancellationTokenSourceExecutor.Token); + long durationMs = stopwatch.ElapsedMilliseconds; + var measures = new Dictionary + { + [TelemetryMeasureName.DurationMs] = durationMs, + [TelemetryMeasureName.BatchCount] = this._rows.Count, + }; + + if (result.Succeeded) + { + this._logger.LogDebugWithThreadId($"Successfully triggered function. Duration={durationMs}ms"); + TelemetryInstance.TrackEvent(TelemetryEventName.TriggerFunctionEnd, this._telemetryProps, measures); + await this.ReleaseLeasesAsync(connection, token); + } + else + { + // In the future might make sense to retry executing the function, but for now we just let + // another worker try. + this._logger.LogError($"Failed to trigger user function for table: '{this._userTable.FullName} due to exception: {result.Exception.GetType()}. Exception message: {result.Exception.Message}"); + TelemetryInstance.TrackException(TelemetryErrorName.ProcessChanges, result.Exception, this._telemetryProps, measures); + + await this.ClearRowsAsync(); + } + } + } + this._logger.LogDebugWithThreadId("END ProcessTableChanges"); + } + + /// + /// Executed once every period. If the state of the change monitor is + /// , then we will renew the leases held by the change monitor on "_rows". + /// + private async void RunLeaseRenewalLoopAsync() + { + this._logger.LogInformation("Starting lease renewal loop."); + + try + { + CancellationToken token = this._cancellationTokenSourceRenewLeases.Token; + + using (var connection = new SqlConnection(this._connectionString)) + { + this._logger.LogDebugWithThreadId("BEGIN OpenLeaseRenewalLoopConnection"); + await connection.OpenAsync(token); + this._logger.LogDebugWithThreadId("END OpenLeaseRenewalLoopConnection"); + + while (!token.IsCancellationRequested) + { + await this.RenewLeasesAsync(connection, token); + await Task.Delay(TimeSpan.FromSeconds(LeaseRenewalIntervalInSeconds), token); + } + } + } + catch (Exception e) + { + // Only want to log the exception if it wasn't caused by StopAsync being called, since Task.Delay throws + // an exception if it's cancelled. + if (e.GetType() != typeof(TaskCanceledException)) + { + this._logger.LogError($"Exiting lease renewal loop due to exception: {e.GetType()}. Exception message: {e.Message}"); + TelemetryInstance.TrackException(TelemetryErrorName.RenewLeasesLoop, e); + } + } + finally + { + this._cancellationTokenSourceRenewLeases.Dispose(); + } + } + + private async Task RenewLeasesAsync(SqlConnection connection, CancellationToken token) + { + this._logger.LogDebugWithThreadId("BEGIN WaitRowsLock - RenewLeases"); + await this._rowsLock.WaitAsync(token); + this._logger.LogDebugWithThreadId("END WaitRowsLock - RenewLeases"); + + if (this._state == State.ProcessingChanges) + { + try + { + // I don't think I need a transaction for renewing leases. If this worker reads in a row from the + // leases table and determines that it corresponds to its batch of changes, but then that row gets + // deleted by a cleanup task, it shouldn't renew the lease on it anyways. + using (SqlCommand renewLeasesCommand = this.BuildRenewLeasesCommand(connection)) + { + TelemetryInstance.TrackEvent(TelemetryEventName.RenewLeasesStart, this._telemetryProps); + this._logger.LogDebugWithThreadId($"BEGIN RenewLeases Query={renewLeasesCommand.CommandText}"); + var stopwatch = Stopwatch.StartNew(); + + await renewLeasesCommand.ExecuteNonQueryAsync(token); + + long durationMs = stopwatch.ElapsedMilliseconds; + this._logger.LogDebugWithThreadId($"END RenewLeases Duration={durationMs}ms"); + var measures = new Dictionary + { + [TelemetryMeasureName.DurationMs] = durationMs, + }; + + TelemetryInstance.TrackEvent(TelemetryEventName.RenewLeasesEnd, this._telemetryProps, measures); + } + } + catch (Exception e) + { + // This catch block is necessary so that the finally block is executed even in the case of an exception + // (see https://docs.microsoft.com/dotnet/csharp/language-reference/keywords/try-finally, third + // paragraph). If we fail to renew the leases, multiple workers could be processing the same change + // data, but we have functionality in place to deal with this (see design doc). + this._logger.LogError($"Failed to renew leases due to exception: {e.GetType()}. Exception message: {e.Message}"); + TelemetryInstance.TrackException(TelemetryErrorName.RenewLeases, e, this._telemetryProps); + } + finally + { + // Do we want to update this count even in the case of a failure to renew the leases? Probably, + // because the count is simply meant to indicate how much time the other thread has spent processing + // changes essentially. + this._leaseRenewalCount += 1; + + // If this thread has been cancelled, then the _cancellationTokenSourceExecutor could have already + // been disposed so shouldn't cancel it. + if (this._leaseRenewalCount == MaxLeaseRenewalCount && !token.IsCancellationRequested) + { + this._logger.LogWarning("Call to execute the function (TryExecuteAsync) seems to be stuck, so it is being cancelled"); + + // If we keep renewing the leases, the thread responsible for processing the changes is stuck. + // If it's stuck, it has to be stuck in the function execution call (I think), so we should + // cancel the call. + this._cancellationTokenSourceExecutor.Cancel(); + this._cancellationTokenSourceExecutor = new CancellationTokenSource(); + } + } + } + + // Want to always release the lock at the end, even if renewing the leases failed. + this._logger.LogDebugWithThreadId("ReleaseRowsLock - RenewLeases"); + this._rowsLock.Release(); + } + + /// + /// Resets the in-memory state of the change monitor and sets it to start polling for changes again. + /// + private async Task ClearRowsAsync() + { + this._logger.LogDebugWithThreadId("BEGIN WaitRowsLock - ClearRows"); + await this._rowsLock.WaitAsync(); + this._logger.LogDebugWithThreadId("END WaitRowsLock - ClearRows"); + + this._leaseRenewalCount = 0; + this._state = State.CheckingForChanges; + this._rows = new List>(); + + this._logger.LogDebugWithThreadId("ReleaseRowsLock - ClearRows"); + this._rowsLock.Release(); + } + + /// + /// Releases the leases held on "_rows". + /// + /// + private async Task ReleaseLeasesAsync(SqlConnection connection, CancellationToken token) + { + TelemetryInstance.TrackEvent(TelemetryEventName.ReleaseLeasesStart, this._telemetryProps); + long newLastSyncVersion = this.RecomputeLastSyncVersion(); + bool retrySucceeded = false; + + for (int retryCount = 1; retryCount <= MaxRetryReleaseLeases && !retrySucceeded; retryCount++) + { + var transactionSw = Stopwatch.StartNew(); + long releaseLeasesDurationMs = 0L, updateLastSyncVersionDurationMs = 0L; + + using (SqlTransaction transaction = connection.BeginTransaction(IsolationLevel.RepeatableRead)) + { + try + { + // Release the leases held on "_rows". + using (SqlCommand releaseLeasesCommand = this.BuildReleaseLeasesCommand(connection, transaction)) + { + this._logger.LogDebugWithThreadId($"BEGIN ReleaseLeases Query={releaseLeasesCommand.CommandText}"); + var commandSw = Stopwatch.StartNew(); + await releaseLeasesCommand.ExecuteNonQueryAsync(token); + releaseLeasesDurationMs = commandSw.ElapsedMilliseconds; + this._logger.LogDebugWithThreadId($"END ReleaseLeases Duration={releaseLeasesDurationMs}ms"); + } + + // Update the global state table if we have processed all changes with ChangeVersion <= newLastSyncVersion, + // and clean up the leases table to remove all rows with ChangeVersion <= newLastSyncVersion. + using (SqlCommand updateTablesPostInvocationCommand = this.BuildUpdateTablesPostInvocation(connection, transaction, newLastSyncVersion)) + { + this._logger.LogDebugWithThreadId($"BEGIN UpdateTablesPostInvocation Query={updateTablesPostInvocationCommand.CommandText}"); + var commandSw = Stopwatch.StartNew(); + await updateTablesPostInvocationCommand.ExecuteNonQueryAsync(token); + updateLastSyncVersionDurationMs = commandSw.ElapsedMilliseconds; + this._logger.LogDebugWithThreadId($"END UpdateTablesPostInvocation Duration={updateLastSyncVersionDurationMs}ms"); + } + + transaction.Commit(); + + var measures = new Dictionary + { + [TelemetryMeasureName.ReleaseLeasesDurationMs] = releaseLeasesDurationMs, + [TelemetryMeasureName.UpdateLastSyncVersionDurationMs] = updateLastSyncVersionDurationMs, + [TelemetryMeasureName.TransactionDurationMs] = transactionSw.ElapsedMilliseconds, + }; + + TelemetryInstance.TrackEvent(TelemetryEventName.ReleaseLeasesEnd, this._telemetryProps, measures); + retrySucceeded = true; + } + catch (Exception ex) + { + if (retryCount < MaxRetryReleaseLeases) + { + this._logger.LogError($"Failed to execute SQL commands to release leases in attempt: {retryCount} for table '{this._userTable.FullName}' due to exception: {ex.GetType()}. Exception message: {ex.Message}"); + + var measures = new Dictionary + { + [TelemetryMeasureName.RetryAttemptNumber] = retryCount, + }; + + TelemetryInstance.TrackException(TelemetryErrorName.ReleaseLeases, ex, this._telemetryProps, measures); + } + else + { + this._logger.LogError($"Failed to release leases for table '{this._userTable.FullName}' after {MaxRetryReleaseLeases} attempts due to exception: {ex.GetType()}. Exception message: {ex.Message}"); + TelemetryInstance.TrackException(TelemetryErrorName.ReleaseLeasesNoRetriesLeft, ex, this._telemetryProps); + } + + try + { + transaction.Rollback(); + } + catch (Exception ex2) + { + this._logger.LogError($"Failed to rollback transaction due to exception: {ex2.GetType()}. Exception message: {ex2.Message}"); + TelemetryInstance.TrackException(TelemetryErrorName.ReleaseLeasesRollback, ex2, this._telemetryProps); + } + } + } + } + + await this.ClearRowsAsync(); + } + + /// + /// Computes the version number that can be potentially used as the new LastSyncVersion in the global state table. + /// + private long RecomputeLastSyncVersion() + { + var changeVersionSet = new SortedSet(); + foreach (IReadOnlyDictionary row in this._rows) + { + string changeVersion = row[SysChangeVersionColumnName].ToString(); + changeVersionSet.Add(long.Parse(changeVersion, CultureInfo.InvariantCulture)); + } + + // The batch of changes are gotten in ascending order of the version number. + // With this, it is ensured that if there are multiple version numbers in the changeVersionSet, + // all the other rows with version numbers less than the highest should have either been processed or + // have leases acquired on them by another worker. + // Therefore, if there are more than one version numbers in the set, return the second highest one. Otherwise, return + // the only version number in the set. + // Also this LastSyncVersion is actually updated in the GlobalState table only after verifying that the changes with + // changeVersion <= newLastSyncVersion have been processed in BuildUpdateTablesPostInvocation query. + long lastSyncVersion = changeVersionSet.ElementAt(changeVersionSet.Count > 1 ? changeVersionSet.Count - 2 : 0); + this._logger.LogDebugWithThreadId($"RecomputeLastSyncVersion. LastSyncVersion={lastSyncVersion} ChangeVersionSet={string.Join(",", changeVersionSet)}"); + return lastSyncVersion; + } + + /// + /// Builds up the list of passed to the user's triggered function based on the data + /// stored in "_rows". If any of the changes correspond to a deleted row, then the + /// will be populated with only the primary key values of the deleted row. + /// + /// The list of changes + private IReadOnlyList> ProcessChanges() + { + this._logger.LogDebugWithThreadId("BEGIN ProcessChanges"); + var changes = new List>(); + foreach (IReadOnlyDictionary row in this._rows) + { + SqlChangeOperation operation = GetChangeOperation(row); + + // If the row has been deleted, there is no longer any data for it in the user table. The best we can do + // is populate the row-item with the primary key values of the row. + Dictionary item = operation == SqlChangeOperation.Delete + ? this._primaryKeyColumns.ToDictionary(col => col.name, col => row[col.name]) + : this._userTableColumns.ToDictionary(col => col, col => row[col]); + + changes.Add(new SqlChange(operation, JsonConvert.DeserializeObject(JsonConvert.SerializeObject(item)))); + } + this._logger.LogDebugWithThreadId("END ProcessChanges"); + return changes; + } + + /// + /// Gets the change associated with this row (either an insert, update or delete). + /// + /// The (combined) row from the change table and leases table + /// Thrown if the value of the "SYS_CHANGE_OPERATION" column is none of "I", "U", or "D" + /// SqlChangeOperation.Insert for an insert, SqlChangeOperation.Update for an update, and SqlChangeOperation.Delete for a delete + private static SqlChangeOperation GetChangeOperation(IReadOnlyDictionary row) + { + string operation = row["SYS_CHANGE_OPERATION"].ToString(); + switch (operation) + { + case "I": return SqlChangeOperation.Insert; + case "U": return SqlChangeOperation.Update; + case "D": return SqlChangeOperation.Delete; + default: throw new InvalidDataException($"Invalid change type encountered in change table row: {row}"); + }; + } + + /// + /// Builds the command to update the global state table in the case of a new minimum valid version number. + /// Sets the LastSyncVersion for this _userTable to be the new minimum valid version number. + /// + /// The connection to add to the returned SqlCommand + /// The transaction to add to the returned SqlCommand + /// The SqlCommand populated with the query and appropriate parameters + private SqlCommand BuildUpdateTablesPreInvocation(SqlConnection connection, SqlTransaction transaction) + { + string updateTablesPreInvocationQuery = $@" + {AppLockStatements} + + DECLARE @min_valid_version bigint; + SET @min_valid_version = CHANGE_TRACKING_MIN_VALID_VERSION({this._userTableId}); + + DECLARE @last_sync_version bigint; + SELECT @last_sync_version = LastSyncVersion + FROM {GlobalStateTableName} + WHERE UserFunctionID = '{this._userFunctionId}' AND UserTableID = {this._userTableId}; + + IF @last_sync_version < @min_valid_version + UPDATE {GlobalStateTableName} + SET LastSyncVersion = @min_valid_version + WHERE UserFunctionID = '{this._userFunctionId}' AND UserTableID = {this._userTableId}; + "; + + return new SqlCommand(updateTablesPreInvocationQuery, connection, transaction); + } + + /// + /// Builds the query to check for changes on the user's table (). + /// + /// The connection to add to the returned SqlCommand + /// The transaction to add to the returned SqlCommand + /// The SqlCommand populated with the query and appropriate parameters + private SqlCommand BuildGetChangesCommand(SqlConnection connection, SqlTransaction transaction) + { + string selectList = string.Join(", ", this._userTableColumns.Select(col => this._primaryKeyColumns.Select(c => c.name).Contains(col) ? $"c.{col.AsBracketQuotedString()}" : $"u.{col.AsBracketQuotedString()}")); + string userTableJoinCondition = string.Join(" AND ", this._primaryKeyColumns.Select(col => $"c.{col.name.AsBracketQuotedString()} = u.{col.name.AsBracketQuotedString()}")); + string leasesTableJoinCondition = string.Join(" AND ", this._primaryKeyColumns.Select(col => $"c.{col.name.AsBracketQuotedString()} = l.{col.name.AsBracketQuotedString()}")); + + string getChangesQuery = $@" + {AppLockStatements} + + DECLARE @last_sync_version bigint; + SELECT @last_sync_version = LastSyncVersion + FROM {GlobalStateTableName} + WHERE UserFunctionID = '{this._userFunctionId}' AND UserTableID = {this._userTableId}; + + SELECT TOP {this._batchSize} + {selectList}, + c.{SysChangeVersionColumnName}, + c.SYS_CHANGE_OPERATION, + l.{LeasesTableChangeVersionColumnName}, + l.{LeasesTableAttemptCountColumnName}, + l.{LeasesTableLeaseExpirationTimeColumnName} + FROM CHANGETABLE(CHANGES {this._userTable.BracketQuotedFullName}, @last_sync_version) AS c + LEFT OUTER JOIN {this._leasesTableName} AS l ON {leasesTableJoinCondition} + LEFT OUTER JOIN {this._userTable.BracketQuotedFullName} AS u ON {userTableJoinCondition} + WHERE + (l.{LeasesTableLeaseExpirationTimeColumnName} IS NULL AND + (l.{LeasesTableChangeVersionColumnName} IS NULL OR l.{LeasesTableChangeVersionColumnName} < c.{SysChangeVersionColumnName}) OR + l.{LeasesTableLeaseExpirationTimeColumnName} < SYSDATETIME() + ) AND + (l.{LeasesTableAttemptCountColumnName} IS NULL OR l.{LeasesTableAttemptCountColumnName} < {MaxChangeProcessAttemptCount}) + ORDER BY c.{SysChangeVersionColumnName} ASC;"; + + return new SqlCommand(getChangesQuery, connection, transaction); + } + + /// + /// Builds the query to get count of unprocessed changes in the user's table. This one mimics the query that is + /// used by workers to get the changes for processing. + /// + /// The connection to add to the returned SqlCommand + /// The SqlCommand populated with the query and appropriate parameters + private SqlCommand BuildGetUnprocessedChangesCommand(SqlConnection connection) + { + string leasesTableJoinCondition = string.Join(" AND ", this._primaryKeyColumns.Select(col => $"c.{col.name.AsBracketQuotedString()} = l.{col.name.AsBracketQuotedString()}")); + + string getUnprocessedChangesQuery = $@" + {AppLockStatements} + + DECLARE @last_sync_version bigint; + SELECT @last_sync_version = LastSyncVersion + FROM {GlobalStateTableName} + WHERE UserFunctionID = '{this._userFunctionId}' AND UserTableID = {this._userTableId}; + + SELECT COUNT_BIG(*) + FROM CHANGETABLE(CHANGES {this._userTable.BracketQuotedFullName}, @last_sync_version) AS c + LEFT OUTER JOIN {this._leasesTableName} AS l ON {leasesTableJoinCondition} + WHERE + (l.{LeasesTableLeaseExpirationTimeColumnName} IS NULL AND + (l.{LeasesTableChangeVersionColumnName} IS NULL OR l.{LeasesTableChangeVersionColumnName} < c.{SysChangeVersionColumnName}) OR + l.{LeasesTableLeaseExpirationTimeColumnName} < SYSDATETIME()) AND + (l.{LeasesTableAttemptCountColumnName} IS NULL OR l.{LeasesTableAttemptCountColumnName} < {MaxChangeProcessAttemptCount}); + "; + + return new SqlCommand(getUnprocessedChangesQuery, connection); + } + + /// + /// Builds the query to acquire leases on the rows in "_rows" if changes are detected in the user's table + /// (). + /// + /// The connection to add to the returned SqlCommand + /// The transaction to add to the returned SqlCommand + /// Dictionary representing the table rows on which leases should be acquired + /// The SqlCommand populated with the query and appropriate parameters + private SqlCommand BuildAcquireLeasesCommand(SqlConnection connection, SqlTransaction transaction, IReadOnlyList> rows) + { + // The column definitions to use for the CTE + IEnumerable cteColumnDefinitions = this._primaryKeyColumns + .Select(c => $"{c.name.AsBracketQuotedString()} {c.type}") + // These are the internal column values that we use. Note that we use SYS_CHANGE_VERSION because that's + // the new version - the _az_func_ChangeVersion has the old version + .Concat(new string[] { $"{SysChangeVersionColumnName} bigint", $"{LeasesTableAttemptCountColumnName} int" }); + IEnumerable bracketedPrimaryKeys = this._primaryKeyColumns.Select(p => p.name.AsBracketQuotedString()); + + // Create the query that the merge statement will match the rows on + string primaryKeyMatchingQuery = string.Join(" AND ", bracketedPrimaryKeys.Select(key => $"ExistingData.{key} = NewData.{key}")); + const string acquireLeasesCte = "acquireLeasesCte"; + const string rowDataParameter = "@rowData"; + // Create the merge query that will either update the rows that already exist or insert a new one if it doesn't exist + string query = $@" + {AppLockStatements} + + WITH {acquireLeasesCte} AS ( SELECT * FROM OPENJSON(@rowData) WITH ({string.Join(",", cteColumnDefinitions)}) ) + MERGE INTO {this._leasesTableName} + AS ExistingData + USING {acquireLeasesCte} + AS NewData + ON + {primaryKeyMatchingQuery} + WHEN MATCHED THEN + UPDATE SET + {LeasesTableChangeVersionColumnName} = NewData.{SysChangeVersionColumnName}, + {LeasesTableAttemptCountColumnName} = ExistingData.{LeasesTableAttemptCountColumnName} + 1, + {LeasesTableLeaseExpirationTimeColumnName} = DATEADD(second, {LeaseIntervalInSeconds}, SYSDATETIME()) + WHEN NOT MATCHED THEN + INSERT VALUES ({string.Join(",", bracketedPrimaryKeys.Select(k => $"NewData.{k}"))}, NewData.{SysChangeVersionColumnName}, 1, DATEADD(second, {LeaseIntervalInSeconds}, SYSDATETIME()));"; + + var command = new SqlCommand(query, connection, transaction); + SqlParameter par = command.Parameters.Add(rowDataParameter, SqlDbType.NVarChar, -1); + string rowData = JsonConvert.SerializeObject(rows); + par.Value = rowData; + return command; + } + + /// + /// Builds the query to renew leases on the rows in "_rows" (). + /// + /// The connection to add to the returned SqlCommand + /// The SqlCommand populated with the query and appropriate parameters + private SqlCommand BuildRenewLeasesCommand(SqlConnection connection) + { + string matchCondition = string.Join(" OR ", this._rowMatchConditions.Take(this._rows.Count)); + + string renewLeasesQuery = $@" + {AppLockStatements} + + UPDATE {this._leasesTableName} + SET {LeasesTableLeaseExpirationTimeColumnName} = DATEADD(second, {LeaseIntervalInSeconds}, SYSDATETIME()) + WHERE {matchCondition}; + "; + + return this.GetSqlCommandWithParameters(renewLeasesQuery, connection, null, this._rows); + } + + /// + /// Builds the query to release leases on the rows in "_rows" after successful invocation of the user's function + /// (). + /// + /// The connection to add to the returned SqlCommand + /// The transaction to add to the returned SqlCommand + /// The SqlCommand populated with the query and appropriate parameters + private SqlCommand BuildReleaseLeasesCommand(SqlConnection connection, SqlTransaction transaction) + { + var releaseLeasesQuery = new StringBuilder( +$@"{AppLockStatements} + +DECLARE @current_change_version bigint; +"); + + for (int rowIndex = 0; rowIndex < this._rows.Count; rowIndex++) + { + string changeVersion = this._rows[rowIndex][SysChangeVersionColumnName].ToString(); + + releaseLeasesQuery.Append($@" + SELECT @current_change_version = {LeasesTableChangeVersionColumnName} + FROM {this._leasesTableName} + WHERE {this._rowMatchConditions[rowIndex]}; + + IF @current_change_version <= {changeVersion} + UPDATE {this._leasesTableName} + SET + {LeasesTableChangeVersionColumnName} = {changeVersion}, + {LeasesTableAttemptCountColumnName} = 0, + {LeasesTableLeaseExpirationTimeColumnName} = NULL + WHERE {this._rowMatchConditions[rowIndex]}; + "); + } + + return this.GetSqlCommandWithParameters(releaseLeasesQuery.ToString(), connection, transaction, this._rows); + } + + /// + /// Builds the command to update the global version number in _globalStateTable after successful invocation of + /// the user's function. If the global version number is updated, also cleans the leases table and removes all + /// rows for which ChangeVersion <= newLastSyncVersion. + /// + /// The connection to add to the returned SqlCommand + /// The transaction to add to the returned SqlCommand + /// The new LastSyncVersion to store in the _globalStateTable for this _userTableName + /// The SqlCommand populated with the query and appropriate parameters + private SqlCommand BuildUpdateTablesPostInvocation(SqlConnection connection, SqlTransaction transaction, long newLastSyncVersion) + { + string leasesTableJoinCondition = string.Join(" AND ", this._primaryKeyColumns.Select(col => $"c.{col.name.AsBracketQuotedString()} = l.{col.name.AsBracketQuotedString()}")); + + string updateTablesPostInvocationQuery = $@" + {AppLockStatements} + + DECLARE @current_last_sync_version bigint; + SELECT @current_last_sync_version = LastSyncVersion + FROM {GlobalStateTableName} + WHERE UserFunctionID = '{this._userFunctionId}' AND UserTableID = {this._userTableId}; + + DECLARE @unprocessed_changes bigint; + SELECT @unprocessed_changes = COUNT(*) FROM ( + SELECT c.{SysChangeVersionColumnName} + FROM CHANGETABLE(CHANGES {this._userTable.BracketQuotedFullName}, @current_last_sync_version) AS c + LEFT OUTER JOIN {this._leasesTableName} AS l ON {leasesTableJoinCondition} + WHERE + c.{SysChangeVersionColumnName} <= {newLastSyncVersion} AND + ((l.{LeasesTableChangeVersionColumnName} IS NULL OR + l.{LeasesTableChangeVersionColumnName} != c.{SysChangeVersionColumnName} OR + l.{LeasesTableLeaseExpirationTimeColumnName} IS NOT NULL) AND + (l.{LeasesTableAttemptCountColumnName} IS NULL OR l.{LeasesTableAttemptCountColumnName} < {MaxChangeProcessAttemptCount}))) AS Changes + + IF @unprocessed_changes = 0 AND @current_last_sync_version < {newLastSyncVersion} + BEGIN + UPDATE {GlobalStateTableName} + SET LastSyncVersion = {newLastSyncVersion} + WHERE UserFunctionID = '{this._userFunctionId}' AND UserTableID = {this._userTableId}; + + DELETE FROM {this._leasesTableName} WHERE {LeasesTableChangeVersionColumnName} <= {newLastSyncVersion}; + END + "; + + return new SqlCommand(updateTablesPostInvocationQuery, connection, transaction); + } + + /// + /// Returns SqlCommand with SqlParameters added to it. Each parameter follows the format + /// (@PrimaryKey_i, PrimaryKeyValue), where @PrimaryKey is the name of a primary key column, and PrimaryKeyValue + /// is one of the row's value for that column. To distinguish between the parameters of different rows, each row + /// will have a distinct value of i. + /// + /// SQL query string + /// The connection to add to the returned SqlCommand + /// The transaction to add to the returned SqlCommand + /// Dictionary representing the table rows + /// + /// Ideally, we would have a map that maps from rows to a list of SqlCommands populated with their primary key + /// values. The issue with this is that SQL doesn't seem to allow adding parameters to one collection when they + /// are part of another. So, for example, since the SqlParameters are part of the list in the map, an exception + /// is thrown if they are also added to the collection of a SqlCommand. The expected behavior seems to be to + /// rebuild the SqlParameters each time. + /// + private SqlCommand GetSqlCommandWithParameters(string commandText, SqlConnection connection, + SqlTransaction transaction, IReadOnlyList> rows) + { + var command = new SqlCommand(commandText, connection, transaction); + + SqlParameter[] parameters = Enumerable.Range(0, rows.Count) + .SelectMany(rowIndex => this._primaryKeyColumns.Select((col, colIndex) => new SqlParameter($"@{rowIndex}_{colIndex}", rows[rowIndex][col.name]))) + .ToArray(); + + command.Parameters.AddRange(parameters); + return command; + } + + private enum State + { + CheckingForChanges, + ProcessingChanges, + } + } +} \ No newline at end of file diff --git a/src/TriggerBinding/SqlTriggerAttribute.cs b/src/TriggerBinding/SqlTriggerAttribute.cs new file mode 100644 index 000000000..2321dd374 --- /dev/null +++ b/src/TriggerBinding/SqlTriggerAttribute.cs @@ -0,0 +1,36 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System; +using Microsoft.Azure.WebJobs.Description; + +namespace Microsoft.Azure.WebJobs +{ + /// + /// Attribute used to bind a parameter to SQL trigger message. + /// + [Binding] + [AttributeUsage(AttributeTargets.Parameter)] + public sealed class SqlTriggerAttribute : Attribute + { + /// + /// Initializes a new instance of the class. + /// + /// Name of the user table + public SqlTriggerAttribute(string tableName) + { + this.TableName = tableName ?? throw new ArgumentNullException(nameof(tableName)); + } + + /// + /// Name of the app setting containing the SQL connection string. + /// + [ConnectionString] + public string ConnectionStringSetting { get; set; } + + /// + /// Name of the user table. + /// + public string TableName { get; } + } +} \ No newline at end of file diff --git a/src/TriggerBinding/SqlTriggerBinding.cs b/src/TriggerBinding/SqlTriggerBinding.cs new file mode 100644 index 000000000..841c8a79e --- /dev/null +++ b/src/TriggerBinding/SqlTriggerBinding.cs @@ -0,0 +1,112 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System; +using System.Collections.Generic; +using System.Reflection; +using System.Security.Cryptography; +using System.Text; +using System.Threading; +using System.Threading.Tasks; +using System.Linq; +using Microsoft.Azure.WebJobs.Host.Bindings; +using Microsoft.Azure.WebJobs.Host.Executors; +using Microsoft.Azure.WebJobs.Host.Listeners; +using Microsoft.Azure.WebJobs.Host.Protocols; +using Microsoft.Azure.WebJobs.Host.Triggers; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Configuration; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql +{ + /// + /// Represents the SQL trigger parameter binding. + /// + /// POCO class representing the row in the user table + internal sealed class SqlTriggerBinding : ITriggerBinding + { + private readonly string _connectionString; + private readonly string _tableName; + private readonly ParameterInfo _parameter; + private readonly IHostIdProvider _hostIdProvider; + private readonly ILogger _logger; + private readonly IConfiguration _configuration; + + private static readonly IReadOnlyDictionary _emptyBindingContract = new Dictionary(); + private static readonly IReadOnlyDictionary _emptyBindingData = new Dictionary(); + + /// + /// Initializes a new instance of the class. + /// + /// SQL connection string used to connect to user database + /// Name of the user table + /// Trigger binding parameter information + /// Provider of unique host identifier + /// Facilitates logging of messages + /// Provides configuration values + public SqlTriggerBinding(string connectionString, string tableName, ParameterInfo parameter, IHostIdProvider hostIdProvider, ILogger logger, IConfiguration configuration) + { + this._connectionString = connectionString ?? throw new ArgumentNullException(nameof(connectionString)); + this._tableName = tableName ?? throw new ArgumentNullException(nameof(tableName)); + this._parameter = parameter ?? throw new ArgumentNullException(nameof(parameter)); + this._hostIdProvider = hostIdProvider ?? throw new ArgumentNullException(nameof(hostIdProvider)); + this._logger = logger ?? throw new ArgumentNullException(nameof(logger)); + this._configuration = configuration ?? throw new ArgumentNullException(nameof(configuration)); + } + + /// + /// Returns the type of trigger value that binds to. + /// + public Type TriggerValueType => typeof(IReadOnlyList>); + + public IReadOnlyDictionary BindingDataContract => _emptyBindingContract; + + public Task BindAsync(object value, ValueBindingContext context) + { + IValueProvider valueProvider = new SqlTriggerValueProvider(this._parameter.ParameterType, value, this._tableName); + return Task.FromResult(new TriggerData(valueProvider, _emptyBindingData)); + } + + public async Task CreateListenerAsync(ListenerFactoryContext context) + { + _ = context ?? throw new ArgumentNullException(nameof(context), "Missing listener context"); + + string userFunctionId = await this.GetUserFunctionIdAsync(); + return new SqlTriggerListener(this._connectionString, this._tableName, userFunctionId, context.Executor, this._logger, this._configuration); + } + + public ParameterDescriptor ToParameterDescriptor() + { + return new SqlTriggerParameterDescriptor + { + Name = this._parameter.Name, + Type = "SqlTrigger", + TableName = this._tableName, + }; + } + + /// + /// Returns an ID that uniquely identifies the user function. + /// + /// We call the WebJobs SDK library method to generate the host ID. The host ID is essentially a hash of the + /// assembly name containing the user function(s). This ensures that if the user ever updates their application, + /// unless the assembly name is modified, the new application version will be able to resume from the point + /// where the previous version had left. Appending another hash of class+method in here ensures that if there + /// are multiple user functions within the same process and tracking the same SQL table, then each one of them + /// gets a separate view of the table changes. + /// + private async Task GetUserFunctionIdAsync() + { + string hostId = await this._hostIdProvider.GetHostIdAsync(CancellationToken.None); + + var methodInfo = (MethodInfo)this._parameter.Member; + string functionName = $"{methodInfo.DeclaringType.FullName}.{methodInfo.Name}"; + + using (var sha256 = SHA256.Create()) + { + byte[] hash = sha256.ComputeHash(Encoding.UTF8.GetBytes(hostId + functionName)); + return new Guid(hash.Take(16).ToArray()).ToString("N").Substring(0, 16); + } + } + } +} \ No newline at end of file diff --git a/src/TriggerBinding/SqlTriggerBindingProvider.cs b/src/TriggerBinding/SqlTriggerBindingProvider.cs new file mode 100644 index 000000000..17afa4cc3 --- /dev/null +++ b/src/TriggerBinding/SqlTriggerBindingProvider.cs @@ -0,0 +1,102 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System; +using System.Collections.Generic; +using System.Reflection; +using System.Threading.Tasks; +using Microsoft.Azure.WebJobs.Host.Executors; +using Microsoft.Azure.WebJobs.Host.Triggers; +using Microsoft.Azure.WebJobs.Logging; +using Microsoft.Extensions.Configuration; +using Microsoft.Extensions.Logging; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql +{ + /// + /// Provider class for SQL trigger parameter binding. + /// + internal sealed class SqlTriggerBindingProvider : ITriggerBindingProvider + { + private readonly IConfiguration _configuration; + private readonly IHostIdProvider _hostIdProvider; + private readonly ILogger _logger; + + /// + /// Initializes a new instance of the class. + /// + /// Configuration to retrieve settings from + /// Provider of unique host identifier + /// Used to create logger instance + public SqlTriggerBindingProvider(IConfiguration configuration, IHostIdProvider hostIdProvider, ILoggerFactory loggerFactory) + { + this._configuration = configuration ?? throw new ArgumentNullException(nameof(configuration)); + this._hostIdProvider = hostIdProvider ?? throw new ArgumentNullException(nameof(hostIdProvider)); + + this._logger = loggerFactory?.CreateLogger(LogCategories.CreateTriggerCategory("Sql")) ?? throw new ArgumentNullException(nameof(loggerFactory)); + } + + /// + /// Creates SQL trigger parameter binding. + /// + /// Contains information about trigger parameter and trigger attributes + /// Thrown if the context is null + /// Thrown if is bound to an invalid parameter type. + /// + /// Null if the user function parameter does not have applied. Otherwise returns an + /// instance, where T is the user-defined POCO type. + /// + public Task TryCreateAsync(TriggerBindingProviderContext context) + { + if (context == null) + { + throw new ArgumentNullException(nameof(context)); + } + + ParameterInfo parameter = context.Parameter; + SqlTriggerAttribute attribute = parameter.GetCustomAttribute(inherit: false); + + // During application startup, the WebJobs SDK calls 'TryCreateAsync' method of all registered trigger + // binding providers in sequence for each parameter in the user function. A provider that finds the + // parameter-attribute that it can handle returns the binding object. Rest of the providers are supposed to + // return null. This binding object later gets used for binding before every function invocation. + if (attribute == null) + { + return Task.FromResult(null); + } + + if (!IsValidTriggerParameterType(parameter.ParameterType)) + { + throw new InvalidOperationException($"Can't bind SqlTriggerAttribute to type {parameter.ParameterType}." + + " Only IReadOnlyList> is supported, where T is the type of user-defined POCO that" + + " matches the schema of the user table"); + } + + string connectionString = SqlBindingUtilities.GetConnectionString(attribute.ConnectionStringSetting, this._configuration); + + // Extract the POCO type 'T' and use it to instantiate class 'SqlTriggerBinding'. + Type userType = parameter.ParameterType.GetGenericArguments()[0].GetGenericArguments()[0]; + Type bindingType = typeof(SqlTriggerBinding<>).MakeGenericType(userType); + + var constructorParameterTypes = new Type[] { typeof(string), typeof(string), typeof(ParameterInfo), typeof(IHostIdProvider), typeof(ILogger), typeof(IConfiguration) }; + ConstructorInfo bindingConstructor = bindingType.GetConstructor(constructorParameterTypes); + + object[] constructorParameterValues = new object[] { connectionString, attribute.TableName, parameter, this._hostIdProvider, this._logger, this._configuration }; + var triggerBinding = (ITriggerBinding)bindingConstructor.Invoke(constructorParameterValues); + + return Task.FromResult(triggerBinding); + } + + /// + /// Checks if the type of trigger parameter in the user function is of form . + /// + private static bool IsValidTriggerParameterType(Type type) + { + return + type.IsGenericType && + type.GetGenericTypeDefinition() == typeof(IReadOnlyList<>) && + type.GetGenericArguments()[0].IsGenericType && + type.GetGenericArguments()[0].GetGenericTypeDefinition() == typeof(SqlChange<>); + } + } +} \ No newline at end of file diff --git a/src/TriggerBinding/SqlTriggerConstants.cs b/src/TriggerBinding/SqlTriggerConstants.cs new file mode 100644 index 000000000..3b9cb47eb --- /dev/null +++ b/src/TriggerBinding/SqlTriggerConstants.cs @@ -0,0 +1,80 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +namespace Microsoft.Azure.WebJobs.Extensions.Sql +{ + internal static class SqlTriggerConstants + { + public const string SchemaName = "az_func"; + + public const string GlobalStateTableName = "[" + SchemaName + "].[GlobalState]"; + + public const string LeasesTableNameFormat = "[" + SchemaName + "].[Leases_{0}]"; + + public const string LeasesTableChangeVersionColumnName = "_az_func_ChangeVersion"; + public const string LeasesTableAttemptCountColumnName = "_az_func_AttemptCount"; + public const string LeasesTableLeaseExpirationTimeColumnName = "_az_func_LeaseExpirationTime"; + public const string SysChangeVersionColumnName = "SYS_CHANGE_VERSION"; + /// + /// The column names that are used in internal state tables and so can't exist in the target table + /// since that shares column names with the primary keys from each user table being monitored. + /// + public static readonly string[] ReservedColumnNames = new string[] + { + LeasesTableChangeVersionColumnName, + LeasesTableAttemptCountColumnName, + LeasesTableLeaseExpirationTimeColumnName + }; + + public const string ConfigKey_SqlTrigger_BatchSize = "Sql_Trigger_BatchSize"; + public const string ConfigKey_SqlTrigger_PollingInterval = "Sql_Trigger_PollingIntervalMs"; + public const string ConfigKey_SqlTrigger_MaxChangesPerWorker = "Sql_Trigger_MaxChangesPerWorker"; + + /// + /// The resource name to use for getting the application lock. We use the same resource name for all instances + /// of the function because there is some shared state across all the functions. + /// + /// A future improvement could be to make unique application locks for each FuncId/TableId combination so that functions + /// working on different tables aren't blocking each other + public const string AppLockResource = "_az_func_Trigger"; + /// + /// Timeout for acquiring the application lock - 30sec chosen as a reasonable value to ensure we aren't + /// hanging infinitely while also giving plenty of time for the blocking transaction to complete. + /// + public const int AppLockTimeoutMs = 30000; + + /// + /// T-SQL statements for getting an application lock. This is used to prevent deadlocks - primarily when multiple instances + /// of a function are running in parallel. + /// + /// The trigger heavily uses transactions to ensure atomic changes, that way if an error occurs during any step of a process we aren't left + /// with an incomplete state. Because of this, locks are placed on rows that are read/modified during the transaction, but the lock isn't + /// applied until the statement itself is executed. Some transactions have many statements executed in a row that touch a number of different + /// tables so it's very easy for two transactions to get in a deadlock depending on the speed they execute their statements and the order they + /// are processed in. + /// + /// So to avoid this we use application locks to ensure that anytime we enter a transaction we first guarantee that we're the only transaction + /// currently making any changes to the tables, which means that we're guaranteed not to have any deadlocks - albeit at the cost of speed. This + /// is acceptable for now, although further investigation could be done into using multiple resources to lock on (such as a different one for each + /// table) to increase the parallelization of the transactions. + /// + /// See the following articles for more information on locking in MSSQL + /// https://learn.microsoft.com/sql/relational-databases/sql-server-transaction-locking-and-row-versioning-guide + /// https://learn.microsoft.com/sql/t-sql/statements/set-transaction-isolation-level-transact-sql + /// https://learn.microsoft.com/sql/relational-databases/system-stored-procedures/sp-getapplock-transact-sql + /// + public static readonly string AppLockStatements = $@"DECLARE @result int; + EXEC @result = sp_getapplock @Resource = '{AppLockResource}', + @LockMode = 'Exclusive', + @LockTimeout = {AppLockTimeoutMs} + IF @result < 0 + BEGIN + RAISERROR('Unable to acquire exclusive lock on {AppLockResource}. Result = %d', 16, 1, @result) + END;"; + + /// + /// There is already an object named '%.*ls' in the database. + /// + public const int ObjectAlreadyExistsErrorNumber = 2714; + } +} diff --git a/src/TriggerBinding/SqlTriggerListener.cs b/src/TriggerBinding/SqlTriggerListener.cs new file mode 100644 index 000000000..7786844ab --- /dev/null +++ b/src/TriggerBinding/SqlTriggerListener.cs @@ -0,0 +1,731 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System; +using System.Collections.Generic; +using System.Diagnostics; +using System.Globalization; +using System.Linq; +using System.Threading; +using System.Threading.Tasks; +using Microsoft.Azure.WebJobs.Extensions.Sql.Telemetry; +using static Microsoft.Azure.WebJobs.Extensions.Sql.Telemetry.Telemetry; +using static Microsoft.Azure.WebJobs.Extensions.Sql.SqlTriggerConstants; +using Microsoft.Azure.WebJobs.Host.Executors; +using Microsoft.Azure.WebJobs.Host.Listeners; +using Microsoft.Azure.WebJobs.Host.Scale; +using Microsoft.Data.SqlClient; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Configuration; +using MoreLinq; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql +{ + /// + /// Represents the listener to SQL table changes. + /// + /// POCO class representing the row in the user table + internal sealed class SqlTriggerListener : IListener, IScaleMonitor + { + private const int ListenerNotStarted = 0; + private const int ListenerStarting = 1; + private const int ListenerStarted = 2; + private const int ListenerStopping = 3; + private const int ListenerStopped = 4; + + // NOTE: please ensure the Readme file and other public documentation are also updated if this value ever + // needs to be changed. + public const int DefaultMaxChangesPerWorker = 1000; + + private readonly SqlObject _userTable; + private readonly string _connectionString; + private readonly string _userFunctionId; + private readonly ITriggeredFunctionExecutor _executor; + private readonly ILogger _logger; + private readonly IConfiguration _configuration; + private readonly ScaleMonitorDescriptor _scaleMonitorDescriptor; + + private readonly IDictionary _telemetryProps = new Dictionary(); + private readonly int _maxChangesPerWorker; + private readonly bool _hasConfiguredMaxChangesPerWorker = false; + + private SqlTableChangeMonitor _changeMonitor; + private int _listenerState = ListenerNotStarted; + + ScaleMonitorDescriptor IScaleMonitor.Descriptor => this._scaleMonitorDescriptor; + + /// + /// Initializes a new instance of the class. + /// + /// SQL connection string used to connect to user database + /// Name of the user table + /// Unique identifier for the user function + /// Defines contract for triggering user function + /// Facilitates logging of messages + /// Provides configuration values + public SqlTriggerListener(string connectionString, string tableName, string userFunctionId, ITriggeredFunctionExecutor executor, ILogger logger, IConfiguration configuration) + { + this._connectionString = !string.IsNullOrEmpty(connectionString) ? connectionString : throw new ArgumentNullException(nameof(connectionString)); + this._userTable = !string.IsNullOrEmpty(tableName) ? new SqlObject(tableName) : throw new ArgumentNullException(nameof(tableName)); + this._userFunctionId = !string.IsNullOrEmpty(userFunctionId) ? userFunctionId : throw new ArgumentNullException(nameof(userFunctionId)); + this._executor = executor ?? throw new ArgumentNullException(nameof(executor)); + this._logger = logger ?? throw new ArgumentNullException(nameof(logger)); + this._configuration = configuration ?? throw new ArgumentNullException(nameof(configuration)); + int? configuredMaxChangesPerWorker; + // Do not convert the scale-monitor ID to lower-case string since SQL table names can be case-sensitive + // depending on the collation of the current database. + this._scaleMonitorDescriptor = new ScaleMonitorDescriptor($"{userFunctionId}-SqlTrigger-{tableName}"); + configuredMaxChangesPerWorker = configuration.GetValue(ConfigKey_SqlTrigger_MaxChangesPerWorker); + this._maxChangesPerWorker = configuredMaxChangesPerWorker ?? DefaultMaxChangesPerWorker; + if (this._maxChangesPerWorker <= 0) + { + throw new InvalidOperationException($"Invalid value for configuration setting '{ConfigKey_SqlTrigger_MaxChangesPerWorker}'. Ensure that the value is a positive integer."); + } + this._hasConfiguredMaxChangesPerWorker = configuredMaxChangesPerWorker != null; + } + + public void Cancel() + { + this.StopAsync(CancellationToken.None).GetAwaiter().GetResult(); + } + + public void Dispose() + { + // Nothing to dispose. + } + + public async Task StartAsync(CancellationToken cancellationToken) + { + int previousState = Interlocked.CompareExchange(ref this._listenerState, ListenerStarting, ListenerNotStarted); + + switch (previousState) + { + case ListenerStarting: throw new InvalidOperationException("The listener is already starting."); + case ListenerStarted: throw new InvalidOperationException("The listener has already started."); + default: break; + } + + this.InitializeTelemetryProps(); + TelemetryInstance.TrackEvent( + TelemetryEventName.StartListenerStart, + new Dictionary(this._telemetryProps) { + { TelemetryPropertyName.HasConfiguredMaxChangesPerWorker, this._hasConfiguredMaxChangesPerWorker.ToString() } + }, + new Dictionary() { + { TelemetryMeasureName.MaxChangesPerWorker, this._maxChangesPerWorker } + } + ); + + try + { + using (var connection = new SqlConnection(this._connectionString)) + { + this._logger.LogDebugWithThreadId("BEGIN OpenListenerConnection"); + await connection.OpenAsync(cancellationToken); + this._logger.LogDebugWithThreadId("END OpenListenerConnection"); + this._telemetryProps.AddConnectionProps(connection); + + int userTableId = await this.GetUserTableIdAsync(connection, cancellationToken); + IReadOnlyList<(string name, string type)> primaryKeyColumns = await this.GetPrimaryKeyColumnsAsync(connection, userTableId, cancellationToken); + IReadOnlyList userTableColumns = await this.GetUserTableColumnsAsync(connection, userTableId, cancellationToken); + + string leasesTableName = string.Format(CultureInfo.InvariantCulture, LeasesTableNameFormat, $"{this._userFunctionId}_{userTableId}"); + this._telemetryProps[TelemetryPropertyName.LeasesTableName] = leasesTableName; + + var transactionSw = Stopwatch.StartNew(); + long createdSchemaDurationMs = 0L, createGlobalStateTableDurationMs = 0L, insertGlobalStateTableRowDurationMs = 0L, createLeasesTableDurationMs = 0L; + + using (SqlTransaction transaction = connection.BeginTransaction(System.Data.IsolationLevel.RepeatableRead)) + { + createdSchemaDurationMs = await this.CreateSchemaAsync(connection, transaction, cancellationToken); + createGlobalStateTableDurationMs = await this.CreateGlobalStateTableAsync(connection, transaction, cancellationToken); + insertGlobalStateTableRowDurationMs = await this.InsertGlobalStateTableRowAsync(connection, transaction, userTableId, cancellationToken); + createLeasesTableDurationMs = await this.CreateLeasesTableAsync(connection, transaction, leasesTableName, primaryKeyColumns, cancellationToken); + transaction.Commit(); + } + + this._logger.LogInformation($"Starting SQL trigger listener for table: '{this._userTable.FullName}', function ID: '{this._userFunctionId}'."); + + this._changeMonitor = new SqlTableChangeMonitor( + this._connectionString, + userTableId, + this._userTable, + this._userFunctionId, + leasesTableName, + userTableColumns, + primaryKeyColumns, + this._executor, + this._logger, + this._configuration, + this._telemetryProps); + + this._listenerState = ListenerStarted; + this._logger.LogInformation($"Started SQL trigger listener for table: '{this._userTable.FullName}', function ID: '{this._userFunctionId}'."); + + var measures = new Dictionary + { + [TelemetryMeasureName.CreatedSchemaDurationMs] = createdSchemaDurationMs, + [TelemetryMeasureName.CreateGlobalStateTableDurationMs] = createGlobalStateTableDurationMs, + [TelemetryMeasureName.InsertGlobalStateTableRowDurationMs] = insertGlobalStateTableRowDurationMs, + [TelemetryMeasureName.CreateLeasesTableDurationMs] = createLeasesTableDurationMs, + [TelemetryMeasureName.TransactionDurationMs] = transactionSw.ElapsedMilliseconds, + }; + + TelemetryInstance.TrackEvent(TelemetryEventName.StartListenerEnd, this._telemetryProps, measures); + } + } + catch (Exception ex) + { + this._listenerState = ListenerNotStarted; + this._logger.LogError($"Failed to start SQL trigger listener for table: '{this._userTable.FullName}', function ID: '{this._userFunctionId}'. Exception: {ex}"); + TelemetryInstance.TrackException(TelemetryErrorName.StartListener, ex, this._telemetryProps); + + throw; + } + } + + public Task StopAsync(CancellationToken cancellationToken) + { + TelemetryInstance.TrackEvent(TelemetryEventName.StopListenerStart, this._telemetryProps); + var stopwatch = Stopwatch.StartNew(); + + int previousState = Interlocked.CompareExchange(ref this._listenerState, ListenerStopping, ListenerStarted); + if (previousState == ListenerStarted) + { + this._changeMonitor.Dispose(); + + this._listenerState = ListenerStopped; + this._logger.LogInformation($"Stopped SQL trigger listener for table: '{this._userTable.FullName}', function ID: '{this._userFunctionId}'."); + } + + var measures = new Dictionary + { + [TelemetryMeasureName.DurationMs] = stopwatch.ElapsedMilliseconds, + }; + + TelemetryInstance.TrackEvent(TelemetryEventName.StopListenerEnd, this._telemetryProps, measures); + return Task.CompletedTask; + } + + /// + /// Returns the object ID of the user table. + /// + /// Thrown in case of error when querying the object ID for the user table + private async Task GetUserTableIdAsync(SqlConnection connection, CancellationToken cancellationToken) + { + string getObjectIdQuery = $"SELECT OBJECT_ID(N{this._userTable.QuotedFullName}, 'U');"; + + this._logger.LogDebugWithThreadId($"BEGIN GetUserTableId Query={getObjectIdQuery}"); + using (var getObjectIdCommand = new SqlCommand(getObjectIdQuery, connection)) + using (SqlDataReader reader = await getObjectIdCommand.ExecuteReaderAsync(cancellationToken)) + { + if (!await reader.ReadAsync(cancellationToken)) + { + throw new InvalidOperationException($"Received empty response when querying the object ID for table: '{this._userTable.FullName}'."); + } + + object userTableId = reader.GetValue(0); + + if (userTableId is DBNull) + { + throw new InvalidOperationException($"Could not find table: '{this._userTable.FullName}'."); + } + this._logger.LogDebugWithThreadId($"END GetUserTableId TableId={userTableId}"); + return (int)userTableId; + } + } + + /// + /// Gets the names and types of primary key columns of the user table. + /// + /// + /// Thrown if there are no primary key columns present in the user table or if their names conflict with columns in leases table. + /// + private async Task> GetPrimaryKeyColumnsAsync(SqlConnection connection, int userTableId, CancellationToken cancellationToken) + { + const int NameIndex = 0, TypeIndex = 1, LengthIndex = 2, PrecisionIndex = 3, ScaleIndex = 4; + string getPrimaryKeyColumnsQuery = $@" + SELECT + c.name, + t.name, + c.max_length, + c.precision, + c.scale + FROM sys.indexes AS i + INNER JOIN sys.index_columns AS ic ON i.object_id = ic.object_id AND i.index_id = ic.index_id + INNER JOIN sys.columns AS c ON ic.object_id = c.object_id AND ic.column_id = c.column_id + INNER JOIN sys.types AS t ON c.user_type_id = t.user_type_id + WHERE i.is_primary_key = 1 AND i.object_id = {userTableId}; + "; + this._logger.LogDebugWithThreadId($"BEGIN GetPrimaryKeyColumns Query={getPrimaryKeyColumnsQuery}"); + using (var getPrimaryKeyColumnsCommand = new SqlCommand(getPrimaryKeyColumnsQuery, connection)) + using (SqlDataReader reader = await getPrimaryKeyColumnsCommand.ExecuteReaderAsync(cancellationToken)) + { + string[] variableLengthTypes = new[] { "varchar", "nvarchar", "nchar", "char", "binary", "varbinary" }; + string[] variablePrecisionTypes = new[] { "numeric", "decimal" }; + + var primaryKeyColumns = new List<(string name, string type)>(); + + while (await reader.ReadAsync(cancellationToken)) + { + string name = reader.GetString(NameIndex); + string type = reader.GetString(TypeIndex); + + if (variableLengthTypes.Contains(type, StringComparer.OrdinalIgnoreCase)) + { + // Special "max" case. I'm actually not sure it's valid to have varchar(max) as a primary key because + // it exceeds the byte limit of an index field (900 bytes), but just in case + short length = reader.GetInt16(LengthIndex); + type += length == -1 ? "(max)" : $"({length})"; + } + else if (variablePrecisionTypes.Contains(type)) + { + byte precision = reader.GetByte(PrecisionIndex); + byte scale = reader.GetByte(ScaleIndex); + type += $"({precision},{scale})"; + } + + primaryKeyColumns.Add((name, type)); + } + + if (primaryKeyColumns.Count == 0) + { + throw new InvalidOperationException($"Could not find primary key created in table: '{this._userTable.FullName}'."); + } + + this._logger.LogDebugWithThreadId($"END GetPrimaryKeyColumns ColumnNames(types) = {string.Join(", ", primaryKeyColumns.Select(col => $"'{col.name}({col.type})'"))}."); + return primaryKeyColumns; + } + } + + /// + /// Gets the column names of the user table. + /// + private async Task> GetUserTableColumnsAsync(SqlConnection connection, int userTableId, CancellationToken cancellationToken) + { + const int NameIndex = 0, TypeIndex = 1, IsAssemblyTypeIndex = 2; + string getUserTableColumnsQuery = $@" + SELECT + c.name, + t.name, + t.is_assembly_type + FROM sys.columns AS c + INNER JOIN sys.types AS t ON c.user_type_id = t.user_type_id + WHERE c.object_id = {userTableId}; + "; + + this._logger.LogDebugWithThreadId($"BEGIN GetUserTableColumns Query={getUserTableColumnsQuery}"); + using (var getUserTableColumnsCommand = new SqlCommand(getUserTableColumnsQuery, connection)) + using (SqlDataReader reader = await getUserTableColumnsCommand.ExecuteReaderAsync(cancellationToken)) + { + var userTableColumns = new List(); + var userDefinedTypeColumns = new List<(string name, string type)>(); + + while (await reader.ReadAsync(cancellationToken)) + { + string columnName = reader.GetString(NameIndex); + string columnType = reader.GetString(TypeIndex); + bool isAssemblyType = reader.GetBoolean(IsAssemblyTypeIndex); + + userTableColumns.Add(columnName); + + if (isAssemblyType) + { + userDefinedTypeColumns.Add((columnName, columnType)); + } + } + + if (userDefinedTypeColumns.Count > 0) + { + string columnNamesAndTypes = string.Join(", ", userDefinedTypeColumns.Select(col => $"'{col.name}' (type: {col.type})")); + throw new InvalidOperationException($"Found column(s) with unsupported type(s): {columnNamesAndTypes} in table: '{this._userTable.FullName}'."); + } + + var conflictingColumnNames = userTableColumns.Intersect(ReservedColumnNames).ToList(); + + if (conflictingColumnNames.Count > 0) + { + string columnNames = string.Join(", ", conflictingColumnNames.Select(col => $"'{col}'")); + throw new InvalidOperationException($"Found reserved column name(s): {columnNames} in table: '{this._userTable.FullName}'." + + " Please rename them to be able to use trigger binding."); + } + + this._logger.LogDebugWithThreadId($"END GetUserTableColumns ColumnNames = {string.Join(", ", userTableColumns.Select(col => $"'{col}'"))}."); + return userTableColumns; + } + } + + /// + /// Creates the schema for global state table and leases tables, if it does not already exist. + /// + /// The already-opened connection to use for executing the command + /// The transaction wrapping this command + /// Cancellation token to pass to the command + /// The time taken in ms to execute the command + private async Task CreateSchemaAsync(SqlConnection connection, SqlTransaction transaction, CancellationToken cancellationToken) + { + string createSchemaQuery = $@" + {AppLockStatements} + + IF SCHEMA_ID(N'{SchemaName}') IS NULL + EXEC ('CREATE SCHEMA {SchemaName}'); + "; + + this._logger.LogDebugWithThreadId($"BEGIN CreateSchema Query={createSchemaQuery}"); + using (var createSchemaCommand = new SqlCommand(createSchemaQuery, connection, transaction)) + { + var stopwatch = Stopwatch.StartNew(); + + try + { + await createSchemaCommand.ExecuteNonQueryAsync(cancellationToken); + } + catch (Exception ex) + { + TelemetryInstance.TrackException(TelemetryErrorName.CreateSchema, ex, this._telemetryProps); + var sqlEx = ex as SqlException; + if (sqlEx?.Number == ObjectAlreadyExistsErrorNumber) + { + // This generally shouldn't happen since we check for its existence in the statement but occasionally + // a race condition can make it so that multiple instances will try and create the schema at once. + // In that case we can just ignore the error since all we care about is that the schema exists at all. + this._logger.LogWarning($"Failed to create schema '{SchemaName}'. Exception message: {ex.Message} This is informational only, function startup will continue as normal."); + } + else + { + throw; + } + } + + long durationMs = stopwatch.ElapsedMilliseconds; + this._logger.LogDebugWithThreadId($"END CreateSchema Duration={durationMs}ms"); + return durationMs; + } + } + + /// + /// Creates the global state table if it does not already exist. + /// + /// The already-opened connection to use for executing the command + /// The transaction wrapping this command + /// Cancellation token to pass to the command + /// The time taken in ms to execute the command + private async Task CreateGlobalStateTableAsync(SqlConnection connection, SqlTransaction transaction, CancellationToken cancellationToken) + { + string createGlobalStateTableQuery = $@" + {AppLockStatements} + + IF OBJECT_ID(N'{GlobalStateTableName}', 'U') IS NULL + CREATE TABLE {GlobalStateTableName} ( + UserFunctionID char(16) NOT NULL, + UserTableID int NOT NULL, + LastSyncVersion bigint NOT NULL, + PRIMARY KEY (UserFunctionID, UserTableID) + ); + "; + + this._logger.LogDebugWithThreadId($"BEGIN CreateGlobalStateTable Query={createGlobalStateTableQuery}"); + using (var createGlobalStateTableCommand = new SqlCommand(createGlobalStateTableQuery, connection, transaction)) + { + var stopwatch = Stopwatch.StartNew(); + try + { + await createGlobalStateTableCommand.ExecuteNonQueryAsync(cancellationToken); + } + catch (Exception ex) + { + TelemetryInstance.TrackException(TelemetryErrorName.CreateGlobalStateTable, ex, this._telemetryProps); + var sqlEx = ex as SqlException; + if (sqlEx?.Number == ObjectAlreadyExistsErrorNumber) + { + // This generally shouldn't happen since we check for its existence in the statement but occasionally + // a race condition can make it so that multiple instances will try and create the schema at once. + // In that case we can just ignore the error since all we care about is that the schema exists at all. + this._logger.LogWarning($"Failed to create global state table '{GlobalStateTableName}'. Exception message: {ex.Message} This is informational only, function startup will continue as normal."); + } + else + { + throw; + } + } + long durationMs = stopwatch.ElapsedMilliseconds; + this._logger.LogDebugWithThreadId($"END CreateGlobalStateTable Duration={durationMs}ms"); + return durationMs; + } + } + + /// + /// Inserts row for the 'user function and table' inside the global state table, if one does not already exist. + /// + /// The already-opened connection to use for executing the command + /// The transaction wrapping this command + /// Cancellation token to pass to the command + /// The time taken in ms to execute the command + private async Task InsertGlobalStateTableRowAsync(SqlConnection connection, SqlTransaction transaction, int userTableId, CancellationToken cancellationToken) + { + object minValidVersion; + + string getMinValidVersionQuery = $"SELECT CHANGE_TRACKING_MIN_VALID_VERSION({userTableId});"; + + this._logger.LogDebugWithThreadId($"BEGIN InsertGlobalStateTableRow"); + this._logger.LogDebugWithThreadId($"BEGIN GetMinValidVersion Query={getMinValidVersionQuery}"); + using (var getMinValidVersionCommand = new SqlCommand(getMinValidVersionQuery, connection, transaction)) + using (SqlDataReader reader = await getMinValidVersionCommand.ExecuteReaderAsync(cancellationToken)) + { + if (!await reader.ReadAsync(cancellationToken)) + { + throw new InvalidOperationException($"Received empty response when querying the 'change tracking min valid version' for table: '{this._userTable.FullName}'."); + } + + minValidVersion = reader.GetValue(0); + + if (minValidVersion is DBNull) + { + throw new InvalidOperationException($"Could not find change tracking enabled for table: '{this._userTable.FullName}'."); + } + } + this._logger.LogDebugWithThreadId($"END GetMinValidVersion MinValidVersion={minValidVersion}"); + + string insertRowGlobalStateTableQuery = $@" + {AppLockStatements} + + IF NOT EXISTS ( + SELECT * FROM {GlobalStateTableName} + WHERE UserFunctionID = '{this._userFunctionId}' AND UserTableID = {userTableId} + ) + INSERT INTO {GlobalStateTableName} + VALUES ('{this._userFunctionId}', {userTableId}, {(long)minValidVersion}); + "; + + this._logger.LogDebugWithThreadId($"BEGIN InsertRowGlobalStateTableQuery Query={insertRowGlobalStateTableQuery}"); + using (var insertRowGlobalStateTableCommand = new SqlCommand(insertRowGlobalStateTableQuery, connection, transaction)) + { + var stopwatch = Stopwatch.StartNew(); + await insertRowGlobalStateTableCommand.ExecuteNonQueryAsync(cancellationToken); + long durationMs = stopwatch.ElapsedMilliseconds; + this._logger.LogDebugWithThreadId($"END InsertRowGlobalStateTableQuery Duration={durationMs}ms"); + this._logger.LogDebugWithThreadId("END InsertGlobalStateTableRow"); + return durationMs; + } + } + + /// + /// Creates the leases table for the 'user function and table', if one does not already exist. + /// + /// The already-opened connection to use for executing the command + /// The transaction wrapping this command + /// The name of the leases table to create + /// The primary keys of the user table this leases table is for + /// Cancellation token to pass to the command + /// The time taken in ms to execute the command + private async Task CreateLeasesTableAsync( + SqlConnection connection, + SqlTransaction transaction, + string leasesTableName, + IReadOnlyList<(string name, string type)> primaryKeyColumns, + CancellationToken cancellationToken) + { + string primaryKeysWithTypes = string.Join(", ", primaryKeyColumns.Select(col => $"{col.name.AsBracketQuotedString()} {col.type}")); + string primaryKeys = string.Join(", ", primaryKeyColumns.Select(col => col.name.AsBracketQuotedString())); + + string createLeasesTableQuery = $@" + {AppLockStatements} + + IF OBJECT_ID(N'{leasesTableName}', 'U') IS NULL + CREATE TABLE {leasesTableName} ( + {primaryKeysWithTypes}, + {LeasesTableChangeVersionColumnName} bigint NOT NULL, + {LeasesTableAttemptCountColumnName} int NOT NULL, + {LeasesTableLeaseExpirationTimeColumnName} datetime2, + PRIMARY KEY ({primaryKeys}) + ); + "; + + this._logger.LogDebugWithThreadId($"BEGIN CreateLeasesTable Query={createLeasesTableQuery}"); + using (var createLeasesTableCommand = new SqlCommand(createLeasesTableQuery, connection, transaction)) + { + var stopwatch = Stopwatch.StartNew(); + try + { + await createLeasesTableCommand.ExecuteNonQueryAsync(cancellationToken); + } + catch (Exception ex) + { + TelemetryInstance.TrackException(TelemetryErrorName.CreateLeasesTable, ex, this._telemetryProps); + var sqlEx = ex as SqlException; + if (sqlEx?.Number == ObjectAlreadyExistsErrorNumber) + { + // This generally shouldn't happen since we check for its existence in the statement but occasionally + // a race condition can make it so that multiple instances will try and create the schema at once. + // In that case we can just ignore the error since all we care about is that the schema exists at all. + this._logger.LogWarning($"Failed to create global state table '{leasesTableName}'. Exception message: {ex.Message} This is informational only, function startup will continue as normal."); + } + else + { + throw; + } + } + long durationMs = stopwatch.ElapsedMilliseconds; + this._logger.LogDebugWithThreadId($"END CreateLeasesTable Duration={durationMs}ms"); + return durationMs; + } + } + + async Task IScaleMonitor.GetMetricsAsync() + { + return await this.GetMetricsAsync(); + } + + public async Task GetMetricsAsync() + { + Debug.Assert(!(this._changeMonitor is null)); + + return new SqlTriggerMetrics + { + UnprocessedChangeCount = await this._changeMonitor.GetUnprocessedChangeCountAsync(), + Timestamp = DateTime.UtcNow, + }; + } + + ScaleStatus IScaleMonitor.GetScaleStatus(ScaleStatusContext context) + { + return this.GetScaleStatusWithTelemetry(context.WorkerCount, context.Metrics?.Cast().ToArray()); + } + + public ScaleStatus GetScaleStatus(ScaleStatusContext context) + { + return this.GetScaleStatusWithTelemetry(context.WorkerCount, context.Metrics?.ToArray()); + } + + private ScaleStatus GetScaleStatusWithTelemetry(int workerCount, SqlTriggerMetrics[] metrics) + { + var status = new ScaleStatus + { + Vote = ScaleVote.None, + }; + + var properties = new Dictionary(this._telemetryProps) + { + [TelemetryPropertyName.ScaleRecommendation] = $"{status.Vote}", + [TelemetryPropertyName.TriggerMetrics] = metrics is null ? "null" : $"[{string.Join(", ", metrics.Select(metric => metric.UnprocessedChangeCount))}]", + [TelemetryPropertyName.WorkerCount] = $"{workerCount}", + }; + + try + { + status = this.GetScaleStatusCore(workerCount, metrics); + + properties[TelemetryPropertyName.ScaleRecommendation] = $"{status.Vote}"; + TelemetryInstance.TrackEvent(TelemetryEventName.GetScaleStatus, properties); + } + catch (Exception ex) + { + this._logger.LogError($"Failed to get scale status for table '{this._userTable.FullName}' due to exception: {ex.GetType()}. Exception message: {ex.Message}"); + TelemetryInstance.TrackException(TelemetryErrorName.GetScaleStatus, ex, properties); + } + + return status; + } + + /// + /// Returns scale recommendation i.e. whether to scale in or out the host application. The recommendation is + /// made based on both the latest metrics and the trend of increase or decrease in the count of unprocessed + /// changes in the user table. In all of the calculations, it is attempted to keep the number of workers minimum + /// while also ensuring that the count of unprocessed changes per worker stays under the maximum limit. + /// + /// The current worker count for the host application. + /// The collection of metrics samples to make the scale decision. + /// + private ScaleStatus GetScaleStatusCore(int workerCount, SqlTriggerMetrics[] metrics) + { + // We require minimum 5 samples to estimate the trend of variation in count of unprocessed changes with + // certain reliability. These samples roughly cover the timespan of past 40 seconds. + const int minSamplesForScaling = 5; + + var status = new ScaleStatus + { + Vote = ScaleVote.None, + }; + + // Do not make a scale decision unless we have enough samples. + if (metrics is null || (metrics.Length < minSamplesForScaling)) + { + this._logger.LogInformation($"Requesting no-scaling: Insufficient metrics for making scale decision for table: '{this._userTable.FullName}'."); + return status; + } + + // Consider only the most recent batch of samples in the rest of the method. + metrics = metrics.TakeLast(minSamplesForScaling).ToArray(); + + string counts = string.Join(", ", metrics.Select(metric => metric.UnprocessedChangeCount)); + this._logger.LogInformation($"Unprocessed change counts: [{counts}], worker count: {workerCount}, maximum changes per worker: {this._maxChangesPerWorker}."); + + // Add worker if the count of unprocessed changes per worker exceeds the maximum limit. + long lastUnprocessedChangeCount = metrics.Last().UnprocessedChangeCount; + if (lastUnprocessedChangeCount > workerCount * this._maxChangesPerWorker) + { + status.Vote = ScaleVote.ScaleOut; + this._logger.LogInformation($"Requesting scale-out: Found too many unprocessed changes for table: '{this._userTable.FullName}' relative to the number of workers."); + return status; + } + + // Check if there is a continuous increase or decrease in count of unprocessed changes. + bool isIncreasing = true; + bool isDecreasing = true; + for (int index = 0; index < metrics.Length - 1; index++) + { + isIncreasing = isIncreasing && metrics[index].UnprocessedChangeCount < metrics[index + 1].UnprocessedChangeCount; + isDecreasing = isDecreasing && (metrics[index + 1].UnprocessedChangeCount == 0 || metrics[index].UnprocessedChangeCount > metrics[index + 1].UnprocessedChangeCount); + } + + if (isIncreasing) + { + // Scale out only if the expected count of unprocessed changes would exceed the combined limit after 30 seconds. + DateTime referenceTime = metrics[metrics.Length - 1].Timestamp - TimeSpan.FromSeconds(30); + SqlTriggerMetrics referenceMetric = metrics.First(metric => metric.Timestamp > referenceTime); + long expectedUnprocessedChangeCount = (2 * metrics[metrics.Length - 1].UnprocessedChangeCount) - referenceMetric.UnprocessedChangeCount; + + if (expectedUnprocessedChangeCount > workerCount * this._maxChangesPerWorker) + { + status.Vote = ScaleVote.ScaleOut; + this._logger.LogInformation($"Requesting scale-out: Found the unprocessed changes for table: '{this._userTable.FullName}' to be continuously increasing" + + " and may exceed the maximum limit set for the workers."); + return status; + } + else + { + this._logger.LogDebug($"Avoiding scale-out: Found the unprocessed changes for table: '{this._userTable.FullName}' to be increasing" + + " but they may not exceed the maximum limit set for the workers."); + } + } + + if (isDecreasing) + { + // Scale in only if the count of unprocessed changes will not exceed the combined limit post the scale-in operation. + if (lastUnprocessedChangeCount <= (workerCount - 1) * this._maxChangesPerWorker) + { + status.Vote = ScaleVote.ScaleIn; + this._logger.LogInformation($"Requesting scale-in: Found table: '{this._userTable.FullName}' to be either idle or the unprocessed changes to be continuously decreasing."); + return status; + } + else + { + this._logger.LogDebug($"Avoiding scale-in: Found the unprocessed changes for table: '{this._userTable.FullName}' to be decreasing" + + " but they are high enough to require all existing workers for processing."); + } + } + + this._logger.LogInformation($"Requesting no-scaling: Found the number of unprocessed changes for table: '{this._userTable.FullName}' to not require scaling."); + return status; + } + + /// + /// Clears the current telemetry property dictionary and initializes the default initial properties. + /// + private void InitializeTelemetryProps() + { + this._telemetryProps.Clear(); + this._telemetryProps[TelemetryPropertyName.UserFunctionId] = this._userFunctionId; + } + } +} \ No newline at end of file diff --git a/src/TriggerBinding/SqlTriggerMetrics.cs b/src/TriggerBinding/SqlTriggerMetrics.cs new file mode 100644 index 000000000..525e5e574 --- /dev/null +++ b/src/TriggerBinding/SqlTriggerMetrics.cs @@ -0,0 +1,15 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using Microsoft.Azure.WebJobs.Host.Scale; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql +{ + internal sealed class SqlTriggerMetrics : ScaleMetrics + { + /// + /// The number of row changes in the user table that are not yet processed. + /// + public long UnprocessedChangeCount { get; set; } + } +} \ No newline at end of file diff --git a/src/TriggerBinding/SqlTriggerParameterDescriptor.cs b/src/TriggerBinding/SqlTriggerParameterDescriptor.cs new file mode 100644 index 000000000..f7a4b19f5 --- /dev/null +++ b/src/TriggerBinding/SqlTriggerParameterDescriptor.cs @@ -0,0 +1,29 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System; +using System.Collections.Generic; +using Microsoft.Azure.WebJobs.Host.Protocols; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql +{ + /// + /// Trigger parameter descriptor for . + /// + internal sealed class SqlTriggerParameterDescriptor : TriggerParameterDescriptor + { + /// + /// Name of the user table. + /// + public string TableName { private get; set; } + + /// + /// Returns descriptive reason for why the user function was triggered. + /// + /// Collection of function arguments (unused) + public override string GetTriggerReason(IDictionary arguments) + { + return $"New change detected on table '{this.TableName}' at {DateTime.UtcNow:o}."; + } + } +} \ No newline at end of file diff --git a/src/TriggerBinding/SqlTriggerValueProvider.cs b/src/TriggerBinding/SqlTriggerValueProvider.cs new file mode 100644 index 000000000..db1d774ac --- /dev/null +++ b/src/TriggerBinding/SqlTriggerValueProvider.cs @@ -0,0 +1,50 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System; +using System.Threading.Tasks; +using Microsoft.Azure.WebJobs.Host.Bindings; + + +namespace Microsoft.Azure.WebJobs.Extensions.Sql +{ + /// + /// Provider for value that will be passed as argument to the triggered function. + /// + internal class SqlTriggerValueProvider : IValueProvider + { + private readonly object _value; + private readonly string _tableName; + + /// + /// Initializes a new instance of the class. + /// + /// Type of the trigger parameter + /// Value of the trigger parameter + /// Name of the user table + public SqlTriggerValueProvider(Type parameterType, object value, string tableName) + { + this.Type = parameterType; + this._value = value; + this._tableName = tableName; + } + + /// + /// Gets the trigger argument value. + /// + public Type Type { get; } + + /// + /// Returns value of the trigger argument. + /// + public Task GetValueAsync() + { + return Task.FromResult(this._value); + } + + public string ToInvokeString() + { + return this._tableName; + } + } +} \ No newline at end of file diff --git a/src/Utils.cs b/src/Utils.cs index d05d01a9a..0bff69855 100644 --- a/src/Utils.cs +++ b/src/Utils.cs @@ -99,5 +99,10 @@ public static void LogDebugWithThreadId(this ILogger logger, string message, par { logger.LogDebug($"TID:{Environment.CurrentManagedThreadId} {message}", args); } + + public static void LogInformationWithThreadId(this ILogger logger, string message, params object[] args) + { + logger.LogInformation($"TID:{Environment.CurrentManagedThreadId} {message}", args); + } } } diff --git a/test/.editorconfig b/test/.editorconfig index 4386dd31a..0082aa2a0 100644 --- a/test/.editorconfig +++ b/test/.editorconfig @@ -5,4 +5,5 @@ # Disabled dotnet_diagnostic.CA1309.severity = silent # Use ordinal StringComparison - this isn't important for tests and just adds clutter dotnet_diagnostic.CA1305.severity = silent # Specify IFormatProvider - this isn't important for tests and just adds clutter -dotnet_diagnostic.CA1707.severity = silent # Identifiers should not contain underscores - this helps make test names more readable \ No newline at end of file +dotnet_diagnostic.CA1707.severity = silent # Identifiers should not contain underscores - this helps make test names more readable +dotnet_diagnostic.CA2201.severity = silent # Do not raise reserved exception types - tests can throw whatever they want \ No newline at end of file diff --git a/test/Common/TestUtils.cs b/test/Common/TestUtils.cs index ffb43d4ec..387418a81 100644 --- a/test/Common/TestUtils.cs +++ b/test/Common/TestUtils.cs @@ -4,7 +4,10 @@ using System; using System.Collections.Generic; using System.Data; +using System.Diagnostics; +using System.Text.RegularExpressions; using System.Threading; +using System.Threading.Tasks; namespace Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Common { @@ -158,5 +161,52 @@ public static string CleanJsonString(string jsonStr) { return jsonStr.Trim().Replace(" ", "").Replace(Environment.NewLine, ""); } + + public static async Task TimeoutAfter(this Task task, TimeSpan timeout, string message = "The operation has timed out.") + { + + using var timeoutCancellationTokenSource = new CancellationTokenSource(); + + Task completedTask = await Task.WhenAny(task, Task.Delay(timeout, timeoutCancellationTokenSource.Token)); + if (completedTask == task) + { + timeoutCancellationTokenSource.Cancel(); + return await task; // Very important in order to propagate exceptions + } + else + { + throw new TimeoutException(message); + } + } + + /// + /// Creates a DataReceievedEventHandler that will wait for the specified regex and then check that + /// the matched group matches the expected value. + /// + /// The task completion source to signal when the value is received + /// The regex. This must have a single group match for the specific value being looked for + /// The name of the value to output if the match fails + /// The value expected to be equal to the matched group from the regex + /// The event handler + public static DataReceivedEventHandler CreateOutputReceievedHandler(TaskCompletionSource taskCompletionSource, string regex, string valueName, string expectedValue) + { + return (object sender, DataReceivedEventArgs e) => + { + Match match = Regex.Match(e.Data, regex); + if (match.Success) + { + // We found the line so now check that the group matches our expected value + string actualValue = match.Groups[1].Value; + if (actualValue == expectedValue) + { + taskCompletionSource.SetResult(true); + } + else + { + taskCompletionSource.SetException(new Exception($"Expected {valueName} value of {expectedValue} but got value {actualValue}")); + } + } + }; + } } } diff --git a/test/Database/Tables/ProductsWithReservedPrimaryKeyColumnNames.sql b/test/Database/Tables/ProductsWithReservedPrimaryKeyColumnNames.sql new file mode 100644 index 000000000..ac05fb59a --- /dev/null +++ b/test/Database/Tables/ProductsWithReservedPrimaryKeyColumnNames.sql @@ -0,0 +1,14 @@ +CREATE TABLE [ProductsWithReservedPrimaryKeyColumnNames] ( + [ProductId] [int] NOT NULL IDENTITY(1, 1), + [_az_func_ChangeVersion] [int] NOT NULL, + [_az_func_AttemptCount] [int] NOT NULL, + [_az_func_LeaseExpirationTime] [int] NOT NULL, + [Name] [nvarchar](100) NULL, + [Cost] [int] NULL, + PRIMARY KEY ( + ProductId, + _az_func_ChangeVersion, + _az_func_AttemptCount, + _az_func_LeaseExpirationTime + ) +); \ No newline at end of file diff --git a/test/Database/Tables/ProductsWithUnsupportedColumnTypes.sql b/test/Database/Tables/ProductsWithUnsupportedColumnTypes.sql new file mode 100644 index 000000000..74eb540d8 --- /dev/null +++ b/test/Database/Tables/ProductsWithUnsupportedColumnTypes.sql @@ -0,0 +1,8 @@ +CREATE TABLE [ProductsWithUnsupportedColumnTypes] ( + [ProductId] [int] NOT NULL PRIMARY KEY, + [Name] [nvarchar](100) NULL, + [Cost] [int] NULL, + [Location] [geography] NULL, + [Geometry] [geometry] NULL, + [Organization] [hierarchyid] NULL +); \ No newline at end of file diff --git a/test/Database/Tables/ProductsWithoutPrimaryKey.sql b/test/Database/Tables/ProductsWithoutPrimaryKey.sql new file mode 100644 index 000000000..c2735b410 --- /dev/null +++ b/test/Database/Tables/ProductsWithoutPrimaryKey.sql @@ -0,0 +1,5 @@ +CREATE TABLE [ProductsWithoutPrimaryKey] ( + [ProductId] [int] NOT NULL, + [Name] [nvarchar](100) NULL, + [Cost] [int] NULL +); \ No newline at end of file diff --git a/test/GlobalSuppressions.cs b/test/GlobalSuppressions.cs index d79999687..54b3acf93 100644 --- a/test/GlobalSuppressions.cs +++ b/test/GlobalSuppressions.cs @@ -13,5 +13,9 @@ [assembly: SuppressMessage("Style", "IDE0060:Remove unused parameter", Justification = "Unused parameter is required by functions binding", Scope = "member", Target = "~M:Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Integration.AddProductMissingColumns.Run(Microsoft.AspNetCore.Http.HttpRequest,Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Common.ProductMissingColumns@)~Microsoft.AspNetCore.Mvc.IActionResult")] [assembly: SuppressMessage("Style", "IDE0060:Remove unused parameter", Justification = "Unused parameter is required by functions binding", Scope = "member", Target = "~M:Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Integration.AddProductMissingColumnsExceptionFunction.Run(Microsoft.AspNetCore.Http.HttpRequest,Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Common.ProductMissingColumns@)~Microsoft.AspNetCore.Mvc.IActionResult")] [assembly: SuppressMessage("Style", "IDE0060:Remove unused parameter", Justification = "Unused parameter is required by functions binding", Scope = "member", Target = "~M:Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Integration.AddProductsNoPartialUpsert.Run(Microsoft.AspNetCore.Http.HttpRequest,Microsoft.Azure.WebJobs.ICollector{Microsoft.Azure.WebJobs.Extensions.Sql.Samples.Common.Product})~Microsoft.AspNetCore.Mvc.IActionResult")] +[assembly: SuppressMessage("Style", "IDE0060:Remove unused parameter", Justification = "Unused parameter is required by functions binding", Scope = "member", Target = "~M:Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Integration.PrimaryKeyNotPresentTrigger.Run(System.Collections.Generic.IReadOnlyList{Microsoft.Azure.WebJobs.Extensions.Sql.SqlChange{Microsoft.Azure.WebJobs.Extensions.Sql.Samples.Common.Product})")] +[assembly: SuppressMessage("Style", "IDE0060:Remove unused parameter", Justification = "Unused parameter is required by functions binding", Scope = "member", Target = "~M:Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Integration.ReservedPrimaryKeyColumnNamesTrigger.Run(System.Collections.Generic.IReadOnlyList{Microsoft.Azure.WebJobs.Extensions.Sql.SqlChange{Microsoft.Azure.WebJobs.Extensions.Sql.Samples.Common.Product})")] +[assembly: SuppressMessage("Style", "IDE0060:Remove unused parameter", Justification = "Unused parameter is required by functions binding", Scope = "member", Target = "~M:Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Integration.TableNotPresentTrigger.Run(System.Collections.Generic.IReadOnlyList{Microsoft.Azure.WebJobs.Extensions.Sql.SqlChange{Microsoft.Azure.WebJobs.Extensions.Sql.Samples.Common.Product})")] +[assembly: SuppressMessage("Style", "IDE0060:Remove unused parameter", Justification = "Unused parameter is required by functions binding", Scope = "member", Target = "~M:Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Integration.UnsupportedColumnTypesTrigger.Run(System.Collections.Generic.IReadOnlyList{Microsoft.Azure.WebJobs.Extensions.Sql.SqlChange{Microsoft.Azure.WebJobs.Extensions.Sql.Samples.Common.Product})")] [assembly: SuppressMessage("Style", "IDE0060:Remove unused parameter", Justification = "Unused parameter is required by functions binding", Scope = "member", Target = "~M:Microsoft.Azure.WebJobs.Extensions.Sql.Samples.InputBindingSamples.GetProductsColumnTypesSerializationAsyncEnumerable.Run(Microsoft.AspNetCore.Http.HttpRequest,System.Collections.Generic.IAsyncEnumerable{Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Common.ProductColumnTypes},Microsoft.Extensions.Logging.ILogger)~System.Threading.Tasks.Task{Microsoft.AspNetCore.Mvc.IActionResult}")] [assembly: SuppressMessage("Style", "IDE0060:Remove unused parameter", Justification = "Unused parameter is required by functions binding", Scope = "member", Target = "~M:Microsoft.Azure.WebJobs.Extensions.Sql.Samples.InputBindingSamples.GetProductsColumnTypesSerialization.Run(Microsoft.AspNetCore.Http.HttpRequest,System.Collections.Generic.IEnumerable{Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Common.ProductColumnTypes},Microsoft.Extensions.Logging.ILogger)~Microsoft.AspNetCore.Mvc.IActionResult")] diff --git a/test/Integration/IntegrationTestBase.cs b/test/Integration/IntegrationTestBase.cs index 38202389c..934db3bdc 100644 --- a/test/Integration/IntegrationTestBase.cs +++ b/test/Integration/IntegrationTestBase.cs @@ -1,22 +1,23 @@ // Copyright (c) Microsoft Corporation. All rights reserved. // Licensed under the MIT License. See License.txt in the project root for license information. -using Microsoft.Data.SqlClient; -using Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Common; using System; +using System.Collections.Generic; using System.Data.Common; using System.Diagnostics; using System.IO; +using System.Linq; using System.Net.Http; using System.Reflection; using System.Runtime.InteropServices; using System.Text; using System.Threading.Tasks; +using Microsoft.AspNetCore.WebUtilities; +using Microsoft.Azure.WebJobs.Extensions.Sql.Samples.Common; +using Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Common; +using Microsoft.Data.SqlClient; using Xunit; using Xunit.Abstractions; -using Microsoft.Azure.WebJobs.Extensions.Sql.Samples.Common; -using Microsoft.AspNetCore.WebUtilities; -using System.Collections.Generic; using static Microsoft.Azure.WebJobs.Extensions.Sql.Telemetry.Telemetry; namespace Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Integration @@ -24,9 +25,14 @@ namespace Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Integration public class IntegrationTestBase : IDisposable { /// - /// Host process for Azure Function CLI + /// The first Function Host process that was started. Null if no process has been started yet. /// - protected Process FunctionHost { get; private set; } + protected Process FunctionHost => this.FunctionHostList.FirstOrDefault(); + + /// + /// Host processes for Azure Function CLI. + /// + protected List FunctionHostList { get; } = new List(); /// /// Host process for Azurite local storage emulator. This is required for non-HTTP trigger functions: @@ -177,56 +183,58 @@ protected void StartAzurite() /// - The functionName is different than its route.
/// - You can start multiple functions by passing in a space-separated list of function names.
/// - protected void StartFunctionHost(string functionName, SupportedLanguages language, bool useTestFolder = false, DataReceivedEventHandler customOutputHandler = null, Dictionary environmentVariables = null) + protected void StartFunctionHost(string functionName, SupportedLanguages language, bool useTestFolder = false, DataReceivedEventHandler customOutputHandler = null, IDictionary environmentVariables = null) { string workingDirectory = language == SupportedLanguages.CSharp && useTestFolder ? GetPathToBin() : Path.Combine(GetPathToBin(), "SqlExtensionSamples", Enum.GetName(typeof(SupportedLanguages), language)); if (!Directory.Exists(workingDirectory)) { throw new FileNotFoundException("Working directory not found at " + workingDirectory); } + + // Use a different port for each new host process, starting with the default port number: 7071. + int port = this.Port + this.FunctionHostList.Count; + var startInfo = new ProcessStartInfo { // The full path to the Functions CLI is required in the ProcessStartInfo because UseShellExecute is set to false. // We cannot both use shell execute and redirect output at the same time: https://docs.microsoft.com//dotnet/api/system.diagnostics.processstartinfo.redirectstandardoutput#remarks FileName = GetFunctionsCoreToolsPath(), - Arguments = $"start --verbose --port {this.Port} --functions {functionName}", + Arguments = $"start --verbose --port {port} --functions {functionName}", WorkingDirectory = workingDirectory, WindowStyle = ProcessWindowStyle.Hidden, RedirectStandardOutput = true, RedirectStandardError = true, UseShellExecute = false }; - if (environmentVariables != null) { - foreach (KeyValuePair variable in environmentVariables) - { - startInfo.EnvironmentVariables[variable.Key] = variable.Value; - } + environmentVariables.ToList().ForEach(ev => startInfo.EnvironmentVariables[ev.Key] = ev.Value); } // Always disable telemetry during test runs startInfo.EnvironmentVariables[TelemetryOptoutEnvVar] = "1"; this.LogOutput($"Starting {startInfo.FileName} {startInfo.Arguments} in {startInfo.WorkingDirectory}"); - this.FunctionHost = new Process + + var functionHost = new Process { StartInfo = startInfo }; + this.FunctionHostList.Add(functionHost); + // Register all handlers before starting the functions host process. var taskCompletionSource = new TaskCompletionSource(); - this.FunctionHost.OutputDataReceived += this.TestOutputHandler; - this.FunctionHost.OutputDataReceived += SignalStartupHandler; + functionHost.OutputDataReceived += SignalStartupHandler; this.FunctionHost.OutputDataReceived += customOutputHandler; - this.FunctionHost.ErrorDataReceived += this.TestOutputHandler; + functionHost.Start(); + functionHost.OutputDataReceived += this.GetTestOutputHandler(functionHost.Id); + functionHost.ErrorDataReceived += this.GetTestOutputHandler(functionHost.Id); + functionHost.BeginOutputReadLine(); + functionHost.BeginErrorReadLine(); - this.FunctionHost.Start(); - this.FunctionHost.BeginOutputReadLine(); - this.FunctionHost.BeginErrorReadLine(); - - this.LogOutput($"Waiting for Azure Function host to start..."); + this.LogOutput("Waiting for Azure Function host to start..."); const int FunctionHostStartupTimeoutInSeconds = 60; bool isCompleted = taskCompletionSource.Task.Wait(TimeSpan.FromSeconds(FunctionHostStartupTimeoutInSeconds)); @@ -237,7 +245,7 @@ protected void StartFunctionHost(string functionName, SupportedLanguages languag const int BufferTimeInSeconds = 5; Task.Delay(TimeSpan.FromSeconds(BufferTimeInSeconds)).Wait(); - this.LogOutput($"Azure Function host started!"); + this.LogOutput("Azure Function host started!"); this.FunctionHost.OutputDataReceived -= SignalStartupHandler; void SignalStartupHandler(object sender, DataReceivedEventArgs e) @@ -297,11 +305,16 @@ private void LogOutput(string output) } } - private void TestOutputHandler(object sender, DataReceivedEventArgs e) + private DataReceivedEventHandler GetTestOutputHandler(int processId) { - if (e != null && !string.IsNullOrEmpty(e.Data)) + return TestOutputHandler; + + void TestOutputHandler(object sender, DataReceivedEventArgs e) { - this.LogOutput(e.Data); + if (!string.IsNullOrEmpty(e.Data)) + { + this.LogOutput($"[{processId}] {e.Data}"); + } } } @@ -381,15 +394,7 @@ public void Dispose() this.LogOutput($"Failed to close connection. Error: {e1.Message}"); } - try - { - this.FunctionHost?.Kill(); - this.FunctionHost?.Dispose(); - } - catch (Exception e2) - { - this.LogOutput($"Failed to stop function host, Error: {e2.Message}"); - } + this.DisposeFunctionHosts(); try { @@ -416,6 +421,26 @@ public void Dispose() GC.SuppressFinalize(this); } + /// + /// Disposes all the running function hosts + /// + protected void DisposeFunctionHosts() + { + foreach (Process functionHost in this.FunctionHostList) + { + try + { + functionHost.Kill(); + functionHost.Dispose(); + } + catch (Exception ex) + { + this.LogOutput($"Failed to stop function host, Error: {ex.Message}"); + } + } + this.FunctionHostList.Clear(); + } + protected async Task SendInputRequest(string functionName, string query = "") { string requestUri = $"http://localhost:{this.Port}/api/{functionName}/{query}"; diff --git a/test/Integration/SqlTriggerBindingIntegrationTests.cs b/test/Integration/SqlTriggerBindingIntegrationTests.cs new file mode 100644 index 000000000..85e6bc954 --- /dev/null +++ b/test/Integration/SqlTriggerBindingIntegrationTests.cs @@ -0,0 +1,637 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System; +using System.Collections.Generic; +using System.Diagnostics; +using System.Linq; +using System.Text; +using System.Threading.Tasks; +using Microsoft.Azure.WebJobs.Extensions.Sql.Samples.Common; +using Microsoft.Azure.WebJobs.Extensions.Sql.Samples.TriggerBindingSamples; +using Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Common; +using Newtonsoft.Json; +using Xunit; +using Xunit.Abstractions; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Integration +{ + [Collection("IntegrationTests")] + public class SqlTriggerBindingIntegrationTests : IntegrationTestBase + { + public SqlTriggerBindingIntegrationTests(ITestOutputHelper output = null) : base(output) + { + this.EnableChangeTrackingForDatabase(); + } + + /// + /// Ensures that the user function gets invoked for each of the insert, update and delete operation. + /// + [Fact] + public async Task SingleOperationTriggerTest() + { + this.SetChangeTrackingForTable("Products"); + this.StartFunctionHost(nameof(ProductsTrigger), SupportedLanguages.CSharp); + + int firstId = 1; + int lastId = 30; + await this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Insert, + () => { this.InsertProducts(firstId, lastId); return Task.CompletedTask; }, + id => $"Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(firstId, lastId)); + + firstId = 1; + lastId = 20; + // All table columns (not just the columns that were updated) would be returned for update operation. + await this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Update, + () => { this.UpdateProducts(firstId, lastId); return Task.CompletedTask; }, + id => $"Updated Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(firstId, lastId)); + + firstId = 11; + lastId = 30; + // The properties corresponding to non-primary key columns would be set to the C# type's default values + // (null and 0) for delete operation. + await this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Delete, + () => { this.DeleteProducts(firstId, lastId); return Task.CompletedTask; }, + _ => null, + _ => 0, + this.GetBatchProcessingTimeout(firstId, lastId)); + } + + /// + /// Verifies that manually setting the batch size correctly changes the number of changes processed at once + /// + [Fact] + public async Task BatchSizeOverrideTriggerTest() + { + // Use enough items to require 4 batches to be processed but then + // set the batch size to the same value so they can all be processed in one + // batch. The test will only wait for ~1 batch worth of time so will timeout + // if the batch size isn't actually changed + const int batchSize = SqlTableChangeMonitor.DefaultBatchSize * 4; + const int firstId = 1; + const int lastId = batchSize; + this.SetChangeTrackingForTable("Products"); + var taskCompletionSource = new TaskCompletionSource(); + DataReceivedEventHandler handler = TestUtils.CreateOutputReceievedHandler( + taskCompletionSource, + @"Starting change consumption loop. BatchSize: (\d*) PollingIntervalMs: \d*", + "BatchSize", + batchSize.ToString()); + this.StartFunctionHost( + nameof(ProductsTriggerWithValidation), + SupportedLanguages.CSharp, + useTestFolder: true, + customOutputHandler: handler, + environmentVariables: new Dictionary() { + { "TEST_EXPECTED_BATCH_SIZE", batchSize.ToString() }, + { "Sql_Trigger_BatchSize", batchSize.ToString() } + } + ); + + await this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Insert, + () => { this.InsertProducts(firstId, lastId); return Task.CompletedTask; }, + id => $"Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(firstId, lastId, batchSize: batchSize)); + await taskCompletionSource.Task.TimeoutAfter(TimeSpan.FromSeconds(5000), "Timed out waiting for BatchSize configuration message"); + } + + /// + /// Verifies that manually setting the polling interval correctly changes the delay between processing each batch of changes + /// + [Fact] + public async Task PollingIntervalOverrideTriggerTest() + { + const int firstId = 1; + // Use enough items to require 5 batches to be processed - the test will + // only wait for the expected time and timeout if the default polling + // interval isn't actually modified. + const int lastId = SqlTableChangeMonitor.DefaultBatchSize * 5; + const int pollingIntervalMs = SqlTableChangeMonitor.DefaultPollingIntervalMs / 2; + this.SetChangeTrackingForTable("Products"); + var taskCompletionSource = new TaskCompletionSource(); + DataReceivedEventHandler handler = TestUtils.CreateOutputReceievedHandler( + taskCompletionSource, + @"Starting change consumption loop. BatchSize: \d* PollingIntervalMs: (\d*)", + "PollingInterval", + pollingIntervalMs.ToString()); + this.StartFunctionHost( + nameof(ProductsTriggerWithValidation), + SupportedLanguages.CSharp, + useTestFolder: true, + customOutputHandler: handler, + environmentVariables: new Dictionary() { + { "Sql_Trigger_PollingIntervalMs", pollingIntervalMs.ToString() } + } + ); + + await this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Insert, + () => { this.InsertProducts(firstId, lastId); return Task.CompletedTask; }, + id => $"Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(firstId, lastId, pollingIntervalMs: pollingIntervalMs)); + await taskCompletionSource.Task.TimeoutAfter(TimeSpan.FromSeconds(5000), "Timed out waiting for PollingInterval configuration message"); + } + + /// + /// Verifies that if several changes have happened to the table row since last invocation, then a single net + /// change for that row is passed to the user function. + /// + [Fact] + public async Task MultiOperationTriggerTest() + { + int firstId = 1; + int lastId = 5; + this.SetChangeTrackingForTable("Products"); + this.StartFunctionHost(nameof(ProductsTrigger), SupportedLanguages.CSharp); + + // 1. Insert + multiple updates to a row are treated as single insert with latest row values. + await this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Insert, + () => + { + this.InsertProducts(firstId, lastId); + this.UpdateProducts(firstId, lastId); + this.UpdateProducts(firstId, lastId); + return Task.CompletedTask; + }, + id => $"Updated Updated Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(firstId, lastId)); + + firstId = 6; + lastId = 10; + // 2. Multiple updates to a row are treated as single update with latest row values. + // First insert items and wait for those changes to be sent + await this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Insert, + () => + { + this.InsertProducts(firstId, lastId); + return Task.CompletedTask; + }, + id => $"Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(firstId, lastId)); + + firstId = 6; + lastId = 10; + // Now do multiple updates at once and verify the updates are batched together + await this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Update, + () => + { + this.UpdateProducts(firstId, lastId); + this.UpdateProducts(firstId, lastId); + return Task.CompletedTask; + }, + id => $"Updated Updated Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(firstId, lastId)); + + firstId = 11; + lastId = 20; + // 3. Insert + (zero or more updates) + delete to a row are treated as single delete with default values for non-primary columns. + await this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Delete, + () => + { + this.InsertProducts(firstId, lastId); + this.UpdateProducts(firstId, lastId); + this.DeleteProducts(firstId, lastId); + return Task.CompletedTask; + }, + _ => null, + _ => 0, + this.GetBatchProcessingTimeout(firstId, lastId)); + } + + /// + /// Ensures correct functionality with multiple user functions tracking the same table. + /// + [Fact] + public async Task MultiFunctionTriggerTest() + { + const string Trigger1Changes = "Trigger1 Changes: "; + const string Trigger2Changes = "Trigger2 Changes: "; + + this.SetChangeTrackingForTable("Products"); + + string functionList = $"{nameof(MultiFunctionTrigger.MultiFunctionTrigger1)} {nameof(MultiFunctionTrigger.MultiFunctionTrigger2)}"; + this.StartFunctionHost(functionList, SupportedLanguages.CSharp, useTestFolder: true); + + // 1. INSERT + int firstId = 1; + int lastId = 30; + // Set up monitoring for Trigger 1... + Task changes1Task = this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Insert, + () => + { + return Task.CompletedTask; + }, + id => $"Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(firstId, lastId), + Trigger1Changes + ); + + // Set up monitoring for Trigger 2... + Task changes2Task = this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Insert, + () => + { + return Task.CompletedTask; + }, + id => $"Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(firstId, lastId), + Trigger2Changes + ); + + // Now that monitoring is set up make the changes and then wait for the monitoring tasks to see them and complete + this.InsertProducts(firstId, lastId); + await Task.WhenAll(changes1Task, changes2Task); + + // 2. UPDATE + firstId = 1; + lastId = 20; + // All table columns (not just the columns that were updated) would be returned for update operation. + // Set up monitoring for Trigger 1... + changes1Task = this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Update, + () => + { + return Task.CompletedTask; + }, + id => $"Updated Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(firstId, lastId), + Trigger1Changes); + + // Set up monitoring for Trigger 2... + changes2Task = this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Update, + () => + { + return Task.CompletedTask; + }, + id => $"Updated Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(firstId, lastId), + Trigger2Changes); + + // Now that monitoring is set up make the changes and then wait for the monitoring tasks to see them and complete + this.UpdateProducts(firstId, lastId); + await Task.WhenAll(changes1Task, changes2Task); + + // 3. DELETE + firstId = 11; + lastId = 30; + // The properties corresponding to non-primary key columns would be set to the C# type's default values + // (null and 0) for delete operation. + // Set up monitoring for Trigger 1... + changes1Task = this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Delete, + () => + { + return Task.CompletedTask; + }, + _ => null, + _ => 0, + this.GetBatchProcessingTimeout(firstId, lastId), + Trigger1Changes); + + // Set up monitoring for Trigger 2... + changes2Task = this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Delete, + () => + { + return Task.CompletedTask; + }, + _ => null, + _ => 0, + this.GetBatchProcessingTimeout(firstId, lastId), + Trigger2Changes); + + // Now that monitoring is set up make the changes and then wait for the monitoring tasks to see them and complete + this.DeleteProducts(firstId, lastId); + await Task.WhenAll(changes1Task, changes2Task); + } + + /// + /// Ensures correct functionality with user functions running across multiple functions host processes. + /// + [Fact] + public async Task MultiHostTriggerTest() + { + this.SetChangeTrackingForTable("Products"); + + // Prepare three function host processes. + this.StartFunctionHost(nameof(ProductsTrigger), SupportedLanguages.CSharp); + this.StartFunctionHost(nameof(ProductsTrigger), SupportedLanguages.CSharp); + this.StartFunctionHost(nameof(ProductsTrigger), SupportedLanguages.CSharp); + + int firstId = 1; + int lastId = 90; + await this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Insert, + () => { this.InsertProducts(firstId, lastId); return Task.CompletedTask; }, + id => $"Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(firstId, lastId)); + + firstId = 1; + lastId = 60; + // All table columns (not just the columns that were updated) would be returned for update operation. + await this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Update, + () => { this.UpdateProducts(firstId, lastId); return Task.CompletedTask; }, + id => $"Updated Product {id}", + id => id * 100, + this.GetBatchProcessingTimeout(firstId, lastId)); + + firstId = 31; + lastId = 90; + // The properties corresponding to non-primary key columns would be set to the C# type's default values + // (null and 0) for delete operation. + await this.WaitForProductChanges( + firstId, + lastId, + SqlChangeOperation.Delete, + () => { this.DeleteProducts(firstId, lastId); return Task.CompletedTask; }, + _ => null, + _ => 0, + this.GetBatchProcessingTimeout(firstId, lastId)); + } + + /// + /// Tests the error message when the user table is not present in the database. + /// + [Fact] + public void TableNotPresentTriggerTest() + { + this.StartFunctionHostAndWaitForError( + nameof(TableNotPresentTrigger), + true, + "Could not find table: 'dbo.TableNotPresent'."); + } + + /// + /// Tests the error message when the user table does not contain primary key. + /// + [Fact] + public void PrimaryKeyNotCreatedTriggerTest() + { + this.StartFunctionHostAndWaitForError( + nameof(PrimaryKeyNotPresentTrigger), + true, + "Could not find primary key created in table: 'dbo.ProductsWithoutPrimaryKey'."); + } + + /// + /// Tests the error message when the user table contains one or more primary keys with names conflicting with + /// column names in the leases table. + /// + [Fact] + public void ReservedPrimaryKeyColumnNamesTriggerTest() + { + this.StartFunctionHostAndWaitForError( + nameof(ReservedPrimaryKeyColumnNamesTrigger), + true, + "Found reserved column name(s): '_az_func_ChangeVersion', '_az_func_AttemptCount', '_az_func_LeaseExpirationTime' in table: 'dbo.ProductsWithReservedPrimaryKeyColumnNames'." + + " Please rename them to be able to use trigger binding."); + } + + /// + /// Tests the error message when the user table contains columns of unsupported SQL types. + /// + [Fact] + public void UnsupportedColumnTypesTriggerTest() + { + this.StartFunctionHostAndWaitForError( + nameof(UnsupportedColumnTypesTrigger), + true, + "Found column(s) with unsupported type(s): 'Location' (type: geography), 'Geometry' (type: geometry), 'Organization' (type: hierarchyid)" + + " in table: 'dbo.ProductsWithUnsupportedColumnTypes'."); + } + + /// + /// Tests the error message when change tracking is not enabled on the user table. + /// + [Fact] + public void ChangeTrackingNotEnabledTriggerTest() + { + this.StartFunctionHostAndWaitForError( + nameof(ProductsTrigger), + false, + "Could not find change tracking enabled for table: 'dbo.Products'."); + } + + private void EnableChangeTrackingForDatabase() + { + this.ExecuteNonQuery($@" + ALTER DATABASE [{this.DatabaseName}] + SET CHANGE_TRACKING = ON + (CHANGE_RETENTION = 2 DAYS, AUTO_CLEANUP = ON); + "); + } + + protected void SetChangeTrackingForTable(string tableName, bool enable = true) + { + this.ExecuteNonQuery($@" + ALTER TABLE [dbo].[{tableName}] + {(enable ? "ENABLE" : "DISABLE")} CHANGE_TRACKING; + "); + } + + protected void InsertProducts(int firstId, int lastId) + { + // Only 1000 items are allowed to be inserted into a single INSERT statement so if we have more than 1000 batch them up into separate statements + var builder = new StringBuilder(); + do + { + int batchCount = Math.Min(lastId - firstId + 1, 1000); + builder.Append($"INSERT INTO [dbo].[Products] VALUES {string.Join(",\n", Enumerable.Range(firstId, batchCount).Select(id => $"({id}, 'Product {id}', {id * 100})"))}; "); + firstId += batchCount; + } while (firstId < lastId); + this.ExecuteNonQuery(builder.ToString()); + } + + protected void UpdateProducts(int firstId, int lastId) + { + int count = lastId - firstId + 1; + this.ExecuteNonQuery( + "UPDATE [dbo].[Products]\n" + + "SET Name = 'Updated ' + Name\n" + + "WHERE ProductId IN (" + string.Join(", ", Enumerable.Range(firstId, count)) + ");"); + } + + protected void DeleteProducts(int firstId, int lastId) + { + int count = lastId - firstId + 1; + this.ExecuteNonQuery( + "DELETE FROM [dbo].[Products]\n" + + "WHERE ProductId IN (" + string.Join(", ", Enumerable.Range(firstId, count)) + ");"); + } + + protected async Task WaitForProductChanges( + int firstId, + int lastId, + SqlChangeOperation operation, + Func actions, + Func getName, + Func getCost, + int timeoutMs, + string messagePrefix = "SQL Changes: ") + { + var expectedIds = Enumerable.Range(firstId, lastId - firstId + 1).ToHashSet(); + int index = 0; + + var taskCompletion = new TaskCompletionSource(); + + void MonitorOutputData(object sender, DataReceivedEventArgs e) + { + if (e.Data != null && (index = e.Data.IndexOf(messagePrefix, StringComparison.Ordinal)) >= 0) + { + string json = e.Data[(index + messagePrefix.Length)..]; + IReadOnlyList> changes = JsonConvert.DeserializeObject>>(json); + foreach (SqlChange change in changes) + { + Assert.Equal(operation, change.Operation); // Expected change operation + Product product = change.Item; + Assert.NotNull(product); // Product deserialized correctly + Assert.Contains(product.ProductID, expectedIds); // We haven't seen this product ID yet, and it's one we expected to see + expectedIds.Remove(product.ProductID); + Assert.Equal(getName(product.ProductID), product.Name); // The product has the expected name + Assert.Equal(getCost(product.ProductID), product.Cost); // The product has the expected cost + } + if (expectedIds.Count == 0) + { + taskCompletion.SetResult(true); + } + } + }; + // Set up listener for the changes coming in + foreach (Process functionHost in this.FunctionHostList) + { + functionHost.OutputDataReceived += MonitorOutputData; + } + + // Now that we've set up our listener trigger the actions to monitor + await actions(); + + // Now wait until either we timeout or we've gotten all the expected changes, whichever comes first + Console.WriteLine($"[{DateTime.UtcNow:u}] Waiting for {operation} changes ({timeoutMs}ms)"); + await taskCompletion.Task.TimeoutAfter(TimeSpan.FromMilliseconds(timeoutMs), $"Timed out waiting for {operation} changes."); + + // Unhook handler since we're done monitoring these changes so we aren't checking other changes done later + foreach (Process functionHost in this.FunctionHostList) + { + functionHost.OutputDataReceived -= MonitorOutputData; + } + } + + /// + /// Launches the functions runtime host, waits for it to encounter error while starting the SQL trigger listener, + /// and asserts that the logged error message matches with the supplied error message. + /// + /// Name of the user function that should cause error in trigger listener + /// Whether the functions host should be launched from test folder + /// Expected error message string + private void StartFunctionHostAndWaitForError(string functionName, bool useTestFolder, string expectedErrorMessage) + { + string errorMessage = null; + var tcs = new TaskCompletionSource(); + + void OutputHandler(object sender, DataReceivedEventArgs e) + { + if (errorMessage == null && e.Data?.Contains("Failed to start SQL trigger listener") == true) + { + // SQL trigger listener throws exception of type InvalidOperationException for all error conditions. + string exceptionPrefix = "Exception: System.InvalidOperationException: "; + int index = e.Data.IndexOf(exceptionPrefix, StringComparison.Ordinal); + Assert.NotEqual(-1, index); + + errorMessage = e.Data[(index + exceptionPrefix.Length)..]; + tcs.SetResult(true); + } + }; + + // All trigger integration tests are only using C# functions for testing at the moment. + this.StartFunctionHost(functionName, SupportedLanguages.CSharp, useTestFolder, OutputHandler); + + // The functions host generally logs the error message within a second after starting up. + const int BufferTimeForErrorInSeconds = 15; + bool isCompleted = tcs.Task.Wait(TimeSpan.FromSeconds(BufferTimeForErrorInSeconds)); + + this.FunctionHost.OutputDataReceived -= OutputHandler; + this.FunctionHost.Kill(); + + Assert.True(isCompleted, "Functions host did not log failure to start SQL trigger listener within specified time."); + Assert.Equal(expectedErrorMessage, errorMessage); + } + + /// + /// Gets a timeout value to use when processing the given number of changes, based on the + /// default batch size and polling interval. + /// + /// The first ID in the batch to process + /// The last ID in the batch to process + /// The batch size if different than the default batch size + /// The polling interval in ms if different than the default polling interval + /// + protected int GetBatchProcessingTimeout(int firstId, int lastId, int batchSize = SqlTableChangeMonitor.DefaultBatchSize, int pollingIntervalMs = SqlTableChangeMonitor.DefaultPollingIntervalMs) + { + int changesToProcess = lastId - firstId + 1; + int calculatedTimeout = (int)(Math.Ceiling((double)changesToProcess / batchSize // The number of batches to process + / this.FunctionHostList.Count) // The number of function host processes + * pollingIntervalMs // The length to process each batch + * 2); // Double to add buffer time for processing results + return Math.Max(calculatedTimeout, 2000); // Always have a timeout of at least 2sec to ensure we have time for processing the results + } + } +} \ No newline at end of file diff --git a/test/Integration/test-csharp/MultiFunctionTrigger.cs b/test/Integration/test-csharp/MultiFunctionTrigger.cs new file mode 100644 index 000000000..66d25b267 --- /dev/null +++ b/test/Integration/test-csharp/MultiFunctionTrigger.cs @@ -0,0 +1,34 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System.Collections.Generic; +using Microsoft.Azure.WebJobs.Extensions.Sql.Samples.Common; +using Microsoft.Extensions.Logging; +using Newtonsoft.Json; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Integration +{ + /// + /// Used to ensure correct functionality with multiple user functions tracking the same table. + /// + public static class MultiFunctionTrigger + { + [FunctionName(nameof(MultiFunctionTrigger1))] + public static void MultiFunctionTrigger1( + [SqlTrigger("[dbo].[Products]", ConnectionStringSetting = "SqlConnectionString")] + IReadOnlyList> products, + ILogger logger) + { + logger.LogInformation("Trigger1 Changes: " + JsonConvert.SerializeObject(products)); + } + + [FunctionName(nameof(MultiFunctionTrigger2))] + public static void MultiFunctionTrigger2( + [SqlTrigger("[dbo].[Products]", ConnectionStringSetting = "SqlConnectionString")] + IReadOnlyList> products, + ILogger logger) + { + logger.LogInformation("Trigger2 Changes: " + JsonConvert.SerializeObject(products)); + } + } +} diff --git a/test/Integration/test-csharp/PrimaryKeyNotPresentTrigger.cs b/test/Integration/test-csharp/PrimaryKeyNotPresentTrigger.cs new file mode 100644 index 000000000..2bdf41085 --- /dev/null +++ b/test/Integration/test-csharp/PrimaryKeyNotPresentTrigger.cs @@ -0,0 +1,23 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System; +using System.Collections.Generic; +using Microsoft.Azure.WebJobs.Extensions.Sql.Samples.Common; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Integration +{ + public static class PrimaryKeyNotPresentTrigger + { + /// + /// Used in verification of the error message when the user table does not contain primary key. + /// + [FunctionName(nameof(PrimaryKeyNotPresentTrigger))] + public static void Run( + [SqlTrigger("[dbo].[ProductsWithoutPrimaryKey]", ConnectionStringSetting = "SqlConnectionString")] + IReadOnlyList> products) + { + throw new NotImplementedException("Associated test case should fail before the function is invoked."); + } + } +} diff --git a/test/Integration/test-csharp/ProductsTriggerWithValidation.cs b/test/Integration/test-csharp/ProductsTriggerWithValidation.cs new file mode 100644 index 000000000..7fca5cbf9 --- /dev/null +++ b/test/Integration/test-csharp/ProductsTriggerWithValidation.cs @@ -0,0 +1,33 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System; +using System.Collections.Generic; +using Microsoft.Azure.WebJobs.Extensions.Sql.Samples.Common; +using Microsoft.Extensions.Logging; +using Newtonsoft.Json; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Integration +{ + public static class ProductsTriggerWithValidation + { + /// + /// Simple trigger function with additional logic to allow for verifying that the expected number + /// of changes was recieved in each batch. + /// + [FunctionName(nameof(ProductsTriggerWithValidation))] + public static void Run( + [SqlTrigger("[dbo].[Products]", ConnectionStringSetting = "SqlConnectionString")] + IReadOnlyList> changes, + ILogger logger) + { + string expectedBatchSize = Environment.GetEnvironmentVariable("TEST_EXPECTED_BATCH_SIZE"); + if (!string.IsNullOrEmpty(expectedBatchSize) && int.Parse(expectedBatchSize) != changes.Count) + { + throw new Exception($"Invalid batch size, got {changes.Count} changes but expected {expectedBatchSize}"); + } + // The output is used to inspect the trigger binding parameter in test methods. + logger.LogInformation("SQL Changes: " + JsonConvert.SerializeObject(changes)); + } + } +} diff --git a/test/Integration/test-csharp/ReservedPrimaryKeyColumnNamesTrigger.cs b/test/Integration/test-csharp/ReservedPrimaryKeyColumnNamesTrigger.cs new file mode 100644 index 000000000..98f67662c --- /dev/null +++ b/test/Integration/test-csharp/ReservedPrimaryKeyColumnNamesTrigger.cs @@ -0,0 +1,24 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System; +using System.Collections.Generic; +using Microsoft.Azure.WebJobs.Extensions.Sql.Samples.Common; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Integration +{ + public static class ReservedPrimaryKeyColumnNamesTrigger + { + /// + /// Used in verification of the error message when the user table contains one or more primary keys with names + /// conflicting with column names in the leases table. + /// + [FunctionName(nameof(ReservedPrimaryKeyColumnNamesTrigger))] + public static void Run( + [SqlTrigger("[dbo].[ProductsWithReservedPrimaryKeyColumnNames]", ConnectionStringSetting = "SqlConnectionString")] + IReadOnlyList> products) + { + throw new NotImplementedException("Associated test case should fail before the function is invoked."); + } + } +} diff --git a/test/Integration/test-csharp/TableNotPresentTrigger.cs b/test/Integration/test-csharp/TableNotPresentTrigger.cs new file mode 100644 index 000000000..345becf53 --- /dev/null +++ b/test/Integration/test-csharp/TableNotPresentTrigger.cs @@ -0,0 +1,23 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System; +using System.Collections.Generic; +using Microsoft.Azure.WebJobs.Extensions.Sql.Samples.Common; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Integration +{ + public static class TableNotPresentTrigger + { + /// + /// Used in verification of the error message when the user table is not present in the database. + /// + [FunctionName(nameof(TableNotPresentTrigger))] + public static void Run( + [SqlTrigger("[dbo].[TableNotPresent]", ConnectionStringSetting = "SqlConnectionString")] + IReadOnlyList> products) + { + throw new NotImplementedException("Associated test case should fail before the function is invoked."); + } + } +} diff --git a/test/Integration/test-csharp/UnsupportedColumnTypesTrigger.cs b/test/Integration/test-csharp/UnsupportedColumnTypesTrigger.cs new file mode 100644 index 000000000..7b15fc817 --- /dev/null +++ b/test/Integration/test-csharp/UnsupportedColumnTypesTrigger.cs @@ -0,0 +1,23 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System; +using System.Collections.Generic; +using Microsoft.Azure.WebJobs.Extensions.Sql.Samples.Common; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Integration +{ + public static class UnsupportedColumnTypesTrigger + { + /// + /// Used in verification of the error message when the user table contains columns of unsupported SQL types. + /// + [FunctionName(nameof(UnsupportedColumnTypesTrigger))] + public static void Run( + [SqlTrigger("[dbo].[ProductsWithUnsupportedColumnTypes]", ConnectionStringSetting = "SqlConnectionString")] + IReadOnlyList> products) + { + throw new NotImplementedException("Associated test case should fail before the function is invoked."); + } + } +} diff --git a/test/README.md b/test/README.md index 7be921e56..42095602d 100644 --- a/test/README.md +++ b/test/README.md @@ -56,7 +56,7 @@ Our integration tests are based on functions from the samples project. To run in this.StartFunctionHost(nameof(), lang); // Replace with the class name of the function this test is running against // test code here } - ``` + ``` Ex: When the test has parameters: ``` @@ -86,4 +86,20 @@ Our integration tests are based on functions from the samples project. To run in this.StartFunctionHost(nameof(), lang); // Replace with the class name of the function this test is running against // test code here } - ``` \ No newline at end of file + ``` + +## Troubleshooting Tests + +This section lists some things to try to help troubleshoot test failures + +### Enable debug logging on the Function + +Enabling debug logging can greatly increase the information available which can help track down issues or understand at least where the problem may be. To enable debug logging for the Function open [host.json](../samples/samples-csharp/host.json) and add the following property to the `logLevel` section, then rebuild and re-run your test. + +```json +"logLevel": { + "default": "Debug" +} +``` + +WARNING : Doing this will add a not-insignificant overhead to the test run duration from writing all the additional content to the log files, which may cause timeouts to occur in tests. If this happens you can temporarily increase those timeouts while debug logging is enabled to avoid having unexpected failures. \ No newline at end of file diff --git a/test/Unit/SqlInputBindingTests.cs b/test/Unit/SqlInputBindingTests.cs index 7143ede05..3d54c6a18 100644 --- a/test/Unit/SqlInputBindingTests.cs +++ b/test/Unit/SqlInputBindingTests.cs @@ -6,6 +6,7 @@ using System.Linq; using System.Threading; using static Microsoft.Azure.WebJobs.Extensions.Sql.SqlConverters; +using Microsoft.Azure.WebJobs.Host.Executors; using Microsoft.Data.SqlClient; using Microsoft.Extensions.Configuration; using Microsoft.Extensions.Logging; @@ -19,6 +20,7 @@ namespace Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Unit public class SqlInputBindingTests { private static readonly Mock config = new(); + private static readonly Mock hostIdProvider = new(); private static readonly Mock loggerFactory = new(); private static readonly Mock logger = new(); private static readonly SqlConnection connection = new(); @@ -26,8 +28,9 @@ public class SqlInputBindingTests [Fact] public void TestNullConfiguration() { - Assert.Throws(() => new SqlBindingConfigProvider(null, loggerFactory.Object)); - Assert.Throws(() => new SqlBindingConfigProvider(config.Object, null)); + Assert.Throws(() => new SqlBindingConfigProvider(null, hostIdProvider.Object, loggerFactory.Object)); + Assert.Throws(() => new SqlBindingConfigProvider(config.Object, null, loggerFactory.Object)); + Assert.Throws(() => new SqlBindingConfigProvider(config.Object, hostIdProvider.Object, null)); Assert.Throws(() => new SqlConverter(null, logger.Object)); Assert.Throws(() => new SqlGenericsConverter(null, logger.Object)); } @@ -41,7 +44,7 @@ public void TestNullCommandText() [Fact] public void TestNullContext() { - var configProvider = new SqlBindingConfigProvider(config.Object, loggerFactory.Object); + var configProvider = new SqlBindingConfigProvider(config.Object, hostIdProvider.Object, loggerFactory.Object); Assert.Throws(() => configProvider.Initialize(null)); } @@ -66,7 +69,7 @@ public void TestNullArgumentsSqlAsyncEnumerableConstructor() } /// - /// SqlAsyncEnumerable should throw InvalidOperationExcepion when invoked with an invalid connection + /// SqlAsyncEnumerable should throw InvalidOperationExcepion when invoked with an invalid connection /// string setting and It should fail here since we're passing an empty connection string. /// [Fact] diff --git a/test/Unit/TriggerBinding/SqlTriggerBindingProviderTests.cs b/test/Unit/TriggerBinding/SqlTriggerBindingProviderTests.cs new file mode 100644 index 000000000..1c0afd352 --- /dev/null +++ b/test/Unit/TriggerBinding/SqlTriggerBindingProviderTests.cs @@ -0,0 +1,103 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System; +using System.Collections.Generic; +using System.Reflection; +using System.Threading; +using System.Threading.Tasks; +using Microsoft.Azure.WebJobs.Host.Executors; +using Microsoft.Azure.WebJobs.Host.Triggers; +using Microsoft.Extensions.Configuration; +using Microsoft.Extensions.Logging; +using Moq; +using Xunit; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Unit +{ + public class SqlTriggerBindingProviderTests + { + /// + /// Verifies that null trigger binding is returned if the trigger parameter in user function does not have + /// applied. + /// + [Fact] + public async Task TryCreateAsync_TriggerParameterWithoutAttribute_ReturnsNullBinding() + { + Type parameterType = typeof(IReadOnlyList>); + ITriggerBinding binding = await CreateTriggerBindingAsync(parameterType, nameof(UserFunctionWithoutAttribute)); + Assert.Null(binding); + } + + /// + /// Verifies that is thrown if the applied on + /// the trigger parameter does not have property set. + /// attribute applied. + /// + [Fact] + public async Task TryCreateAsync_MissingConnectionString_ThrowsException() + { + Type parameterType = typeof(IReadOnlyList>); + Task testCode() { return CreateTriggerBindingAsync(parameterType, nameof(UserFunctionWithoutConnectionString)); } + ArgumentException exception = await Assert.ThrowsAsync(testCode); + + Assert.Equal( + "Must specify ConnectionStringSetting, which should refer to the name of an app setting that contains a SQL connection string", + exception.Message); + } + + /// + /// Verifies that is thrown if the is + /// applied on the trigger parameter of unsupported type. + /// + [Theory] + [InlineData(typeof(object))] + [InlineData(typeof(SqlChange))] + [InlineData(typeof(IEnumerable>))] + [InlineData(typeof(IReadOnlyList))] + [InlineData(typeof(IReadOnlyList>))] + public async Task TryCreateAsync_InvalidTriggerParameterType_ThrowsException(Type parameterType) + { + Task testCode() { return CreateTriggerBindingAsync(parameterType, nameof(UserFunctionWithoutConnectionString)); } + InvalidOperationException exception = await Assert.ThrowsAsync(testCode); + + Assert.Equal( + $"Can't bind SqlTriggerAttribute to type {parameterType}. Only IReadOnlyList> is supported, where T is the type of user-defined POCO that matches the schema of the user table", + exception.Message); + } + + /// + /// Verifies that is returned if the has all + /// required properties set and it is applied on the trigger parameter of supported type. + /// + [Fact] + public async Task TryCreateAsync_ValidTriggerParameterType_ReturnsTriggerBinding() + { + Type parameterType = typeof(IReadOnlyList>); + ITriggerBinding binding = await CreateTriggerBindingAsync(parameterType, nameof(UserFunctionWithAttribute)); + Assert.IsType>(binding); + } + + private static async Task CreateTriggerBindingAsync(Type parameterType, string methodName) + { + var provider = new SqlTriggerBindingProvider( + Mock.Of(c => c["testConnectionStringSetting"] == "testConnectionString"), + Mock.Of(), + Mock.Of(f => f.CreateLogger(It.IsAny()) == Mock.Of())); + + // Possibly the simplest way to construct a ParameterInfo object. + ParameterInfo parameter = typeof(SqlTriggerBindingProviderTests) + .GetMethod(methodName, BindingFlags.NonPublic | BindingFlags.Static) + .MakeGenericMethod(parameterType) + .GetParameters()[0]; + + return await provider.TryCreateAsync(new TriggerBindingProviderContext(parameter, CancellationToken.None)); + } + + private static void UserFunctionWithoutAttribute(T _) { } + + private static void UserFunctionWithoutConnectionString([SqlTrigger("testTableName")] T _) { } + + private static void UserFunctionWithAttribute([SqlTrigger("testTableName", ConnectionStringSetting = "testConnectionStringSetting")] T _) { } + } +} \ No newline at end of file diff --git a/test/Unit/TriggerBinding/SqlTriggerListenerTests.cs b/test/Unit/TriggerBinding/SqlTriggerListenerTests.cs new file mode 100644 index 000000000..6f50e099f --- /dev/null +++ b/test/Unit/TriggerBinding/SqlTriggerListenerTests.cs @@ -0,0 +1,321 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +using System; +using System.Collections.Generic; +using System.Linq; +using Microsoft.Azure.WebJobs.Host.Executors; +using Microsoft.Azure.WebJobs.Host.Scale; +using Microsoft.Extensions.Configuration; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Logging.Internal; +using Moq; +using Xunit; + +namespace Microsoft.Azure.WebJobs.Extensions.Sql.Tests.Unit +{ + public class SqlTriggerListenerTests + { + /// + /// Verifies that the scale monitor descriptor ID is set to expected value. + /// + [Theory] + [InlineData("testTableName", "testUserFunctionId", "testUserFunctionId-SqlTrigger-testTableName")] + [InlineData("тестТаблицаИмя", "тестПользовательФункцияИд", "тестПользовательФункцияИд-SqlTrigger-тестТаблицаИмя")] + public void ScaleMonitorDescriptor_ReturnsExpectedValue(string tableName, string userFunctionId, string expectedDescriptorId) + { + IScaleMonitor monitor = GetScaleMonitor(tableName, userFunctionId); + Assert.Equal(expectedDescriptorId, monitor.Descriptor.Id); + } + + /// + /// Verifies that no-scaling is requested if there are insufficient metrics available for making the scale + /// decision. + /// + [Theory] + [InlineData(null)] // metrics == null + [InlineData(new int[] { })] // metrics.Length == 0 + [InlineData(new int[] { 1000, 1000, 1000, 1000 })] // metrics.Length == 4. + public void ScaleMonitorGetScaleStatus_InsufficentMetrics_ReturnsNone(int[] unprocessedChangeCounts) + { + (IScaleMonitor monitor, List logMessages) = GetScaleMonitor(); + ScaleStatusContext context = GetScaleStatusContext(unprocessedChangeCounts, 0); + + ScaleStatus scaleStatus = monitor.GetScaleStatus(context); + + Assert.Equal(ScaleVote.None, scaleStatus.Vote); + Assert.Contains("Requesting no-scaling: Insufficient metrics for making scale decision for table: 'testTableName'.", logMessages); + } + + /// + /// Verifies that only the most recent samples are considered for making the scale decision. + /// + [Theory] + [InlineData(new int[] { 0, 0, 4, 3, 2, 0 }, 2, ScaleVote.None)] + [InlineData(new int[] { 0, 0, 4, 3, 2, 1, 0 }, 2, ScaleVote.ScaleIn)] + [InlineData(new int[] { 1000, 1000, 0, 1, 2, 1000 }, 1, ScaleVote.None)] + [InlineData(new int[] { 1000, 1000, 0, 1, 2, 3, 1000 }, 1, ScaleVote.ScaleOut)] + public void ScaleMonitorGetScaleStatus_ExcessMetrics_IgnoresExcessMetrics(int[] unprocessedChangeCounts, int workerCount, ScaleVote scaleVote) + { + (IScaleMonitor monitor, _) = GetScaleMonitor(); + ScaleStatusContext context = GetScaleStatusContext(unprocessedChangeCounts, workerCount); + + ScaleStatus scaleStatus = monitor.GetScaleStatus(context); + + Assert.Equal(scaleVote, scaleStatus.Vote); + } + + /// + /// Verifies that scale-out is requested if the latest count of unprocessed changes is above the combined limit + /// of all workers. + /// + [Theory] + [InlineData(new int[] { 0, 0, 0, 0, 1 }, 0)] + [InlineData(new int[] { 0, 0, 0, 0, 1001 }, 1)] + [InlineData(new int[] { 0, 0, 0, 0, 10001 }, 10)] + public void ScaleMonitorGetScaleStatus_LastCountAboveLimit_ReturnsScaleOut(int[] unprocessedChangeCounts, int workerCount) + { + (IScaleMonitor monitor, List logMessages) = GetScaleMonitor(); + ScaleStatusContext context = GetScaleStatusContext(unprocessedChangeCounts, workerCount); + + ScaleStatus scaleStatus = monitor.GetScaleStatus(context); + + Assert.Equal(ScaleVote.ScaleOut, scaleStatus.Vote); + Assert.Contains("Requesting scale-out: Found too many unprocessed changes for table: 'testTableName' relative to the number of workers.", logMessages); + } + + /// + /// Verifies that no-scaling is requested if the latest count of unprocessed changes is not above the combined + /// limit of all workers. + /// + [Theory] + [InlineData(new int[] { 0, 0, 0, 0, 0 }, 0)] + [InlineData(new int[] { 0, 0, 0, 0, 1000 }, 1)] + [InlineData(new int[] { 0, 0, 0, 0, 10000 }, 10)] + public void ScaleMonitorGetScaleStatus_LastCountBelowLimit_ReturnsNone(int[] unprocessedChangeCounts, int workerCount) + { + (IScaleMonitor monitor, List logMessages) = GetScaleMonitor(); + ScaleStatusContext context = GetScaleStatusContext(unprocessedChangeCounts, workerCount); + + ScaleStatus scaleStatus = monitor.GetScaleStatus(context); + + Assert.Equal(ScaleVote.None, scaleStatus.Vote); + Assert.Contains("Requesting no-scaling: Found the number of unprocessed changes for table: 'testTableName' to not require scaling.", logMessages); + } + + /// + /// Verifies that scale-out is requested if the count of unprocessed changes is strictly increasing and may + /// exceed the combined limit of all workers. Since the metric samples are separated by 10 seconds, the existing + /// implementation should only consider the last three samples in its calculation. + /// + [Theory] + [InlineData(new int[] { 0, 1, 500, 501, 751 }, 1)] + [InlineData(new int[] { 0, 1, 4999, 5001, 7500 }, 10)] + public void ScaleMonitorGetScaleStatus_CountIncreasingAboveLimit_ReturnsScaleOut(int[] unprocessedChangeCounts, int workerCount) + { + (IScaleMonitor monitor, List logMessages) = GetScaleMonitor(); + ScaleStatusContext context = GetScaleStatusContext(unprocessedChangeCounts, workerCount); + + ScaleStatus scaleStatus = monitor.GetScaleStatus(context); + + Assert.Equal(ScaleVote.ScaleOut, scaleStatus.Vote); + Assert.Contains("Requesting scale-out: Found the unprocessed changes for table: 'testTableName' to be continuously increasing and may exceed the maximum limit set for the workers.", logMessages); + } + + /// + /// Verifies that no-scaling is requested if the count of unprocessed changes is strictly increasing but it may + /// still stay below the combined limit of all workers. Since the metric samples are separated by 10 seconds, + /// the existing implementation should only consider the last three samples in its calculation. + /// + [Theory] + [InlineData(new int[] { 0, 1, 500, 501, 750 }, 1)] + [InlineData(new int[] { 0, 1, 5000, 5001, 7500 }, 10)] + public void ScaleMonitorGetScaleStatus_CountIncreasingBelowLimit_ReturnsNone(int[] unprocessedChangeCounts, int workerCount) + { + (IScaleMonitor monitor, List logMessages) = GetScaleMonitor(); + ScaleStatusContext context = GetScaleStatusContext(unprocessedChangeCounts, workerCount); + + ScaleStatus scaleStatus = monitor.GetScaleStatus(context); + + Assert.Equal(ScaleVote.None, scaleStatus.Vote); + Assert.Contains("Avoiding scale-out: Found the unprocessed changes for table: 'testTableName' to be increasing but they may not exceed the maximum limit set for the workers.", logMessages); + } + + /// + /// Verifies that scale-in is requested if the count of unprocessed changes is strictly decreasing (or zero) and + /// is also below the combined limit of workers after being reduced by one. + /// + [Theory] + [InlineData(new int[] { 0, 0, 0, 0, 0 }, 1)] + [InlineData(new int[] { 1, 0, 0, 0, 0 }, 1)] + [InlineData(new int[] { 5, 4, 3, 2, 0 }, 1)] + [InlineData(new int[] { 9005, 9004, 9003, 9002, 9000 }, 10)] + public void ScaleMonitorGetScaleStatus_CountDecreasingBelowLimit_ReturnsScaleIn(int[] unprocessedChangeCounts, int workerCount) + { + (IScaleMonitor monitor, List logMessages) = GetScaleMonitor(); + ScaleStatusContext context = GetScaleStatusContext(unprocessedChangeCounts, workerCount); + + ScaleStatus scaleStatus = monitor.GetScaleStatus(context); + + Assert.Equal(ScaleVote.ScaleIn, scaleStatus.Vote); + Assert.Contains("Requesting scale-in: Found table: 'testTableName' to be either idle or the unprocessed changes to be continuously decreasing.", logMessages); + } + + /// + /// Verifies that scale-in is requested if the count of unprocessed changes is strictly decreasing (or zero) but + /// it is still above the combined limit of workers after being reduced by one. + /// + [Theory] + [InlineData(new int[] { 5, 4, 3, 2, 1 }, 1)] + [InlineData(new int[] { 9005, 9004, 9003, 9002, 9001 }, 10)] + public void ScaleMonitorGetScaleStatus_CountDecreasingAboveLimit_ReturnsNone(int[] unprocessedChangeCounts, int workerCount) + { + (IScaleMonitor monitor, List logMessages) = GetScaleMonitor(); + ScaleStatusContext context = GetScaleStatusContext(unprocessedChangeCounts, workerCount); + + ScaleStatus scaleStatus = monitor.GetScaleStatus(context); + + Assert.Equal(ScaleVote.None, scaleStatus.Vote); + Assert.Contains("Avoiding scale-in: Found the unprocessed changes for table: 'testTableName' to be decreasing but they are high enough to require all existing workers for processing.", logMessages); + } + + /// + /// Verifies that no-scaling is requested if the count of unprocessed changes is neither strictly increasing and + /// nor strictly decreasing. + /// + [Theory] + [InlineData(new int[] { 0, 0, 1, 2, 3 }, 1)] + [InlineData(new int[] { 1, 1, 0, 0, 0 }, 10)] + public void ScaleMonitorGetScaleStatus_CountNotIncreasingOrDecreasing_ReturnsNone(int[] unprocessedChangeCounts, int workerCount) + { + (IScaleMonitor monitor, List logMessages) = GetScaleMonitor(); + ScaleStatusContext context = GetScaleStatusContext(unprocessedChangeCounts, workerCount); + + ScaleStatus scaleStatus = monitor.GetScaleStatus(context); + + Assert.Equal(ScaleVote.None, scaleStatus.Vote); + + // Ensure that no-scaling was not requested because of other conditions. + Assert.DoesNotContain("Avoiding scale-out: Found the unprocessed changes for table: 'testTableName' to be increasing but they may not exceed the maximum limit set for the workers.", logMessages); + Assert.DoesNotContain("Avoiding scale-in: Found the unprocessed changes for table: 'testTableName' to be decreasing but they are high enough to require all existing workers for processing.", logMessages); + Assert.Contains("Requesting no-scaling: Found the number of unprocessed changes for table: 'testTableName' to not require scaling.", logMessages); + } + + [Theory] + [InlineData("1")] + [InlineData("100")] + [InlineData("10000")] + public void ScaleMonitorGetScaleStatus_UserConfiguredMaxChangesPerWorker_RespectsConfiguration(string maxChangesPerWorker) + { + (IScaleMonitor monitor, _) = GetScaleMonitor(maxChangesPerWorker); + + ScaleStatusContext context; + ScaleStatus scaleStatus; + + int max = int.Parse(maxChangesPerWorker); + + context = GetScaleStatusContext(new int[] { 0, 0, 0, 0, 10 * max }, 10); + scaleStatus = monitor.GetScaleStatus(context); + Assert.Equal(ScaleVote.None, scaleStatus.Vote); + + context = GetScaleStatusContext(new int[] { 0, 0, 0, 0, (10 * max) + 1 }, 10); + scaleStatus = monitor.GetScaleStatus(context); + Assert.Equal(ScaleVote.ScaleOut, scaleStatus.Vote); + + context = GetScaleStatusContext(new int[] { (9 * max) + 4, (9 * max) + 3, (9 * max) + 2, (9 * max) + 1, 9 * max }, 10); + scaleStatus = monitor.GetScaleStatus(context); + Assert.Equal(ScaleVote.ScaleIn, scaleStatus.Vote); + } + + [Theory] + [InlineData("invalidValue")] + [InlineData("-1")] + [InlineData("0")] + [InlineData("10000000000")] + public void InvalidUserConfiguredMaxChangesPerWorker(string maxChangesPerWorker) + { + (Mock mockLogger, List logMessages) = CreateMockLogger(); + Mock mockConfiguration = CreateMockConfiguration(maxChangesPerWorker); + + Assert.Throws(() => new SqlTriggerListener("testConnectionString", "testTableName", "testUserFunctionId", Mock.Of(), mockLogger.Object, mockConfiguration.Object)); + } + + private static IScaleMonitor GetScaleMonitor(string tableName, string userFunctionId) + { + Mock mockConfiguration = CreateMockConfiguration(); + + return new SqlTriggerListener( + "testConnectionString", + tableName, + userFunctionId, + Mock.Of(), + Mock.Of(), + mockConfiguration.Object); + } + + private static (IScaleMonitor monitor, List logMessages) GetScaleMonitor(string maxChangesPerWorker = null) + { + (Mock mockLogger, List logMessages) = CreateMockLogger(); + Mock mockConfiguration = CreateMockConfiguration(maxChangesPerWorker); + + IScaleMonitor monitor = new SqlTriggerListener( + "testConnectionString", + "testTableName", + "testUserFunctionId", + Mock.Of(), + mockLogger.Object, + mockConfiguration.Object); + + return (monitor, logMessages); + } + + private static ScaleStatusContext GetScaleStatusContext(int[] unprocessedChangeCounts, int workerCount) + { + DateTime now = DateTime.UtcNow; + + // Returns metric samples separated by 10 seconds. The time-difference is essential for testing the + // scale-out logic. + return new ScaleStatusContext + { + Metrics = unprocessedChangeCounts?.Select((count, index) => new SqlTriggerMetrics + { + UnprocessedChangeCount = count, + Timestamp = now + TimeSpan.FromSeconds(10 * index), + }), + WorkerCount = workerCount, + }; + } + + private static (Mock logger, List logMessages) CreateMockLogger() + { + // Since multiple threads are not involved when computing the scale-status, it should be okay to not use + // a thread-safe collection for storing the log messages. + var logMessages = new List(); + var mockLogger = new Mock(); + + // Both LogInformation and LogDebug are extension (static) methods and cannot be mocked. Hence, we need to + // setup callback on an inner class method that gets eventually called by these methods in order to extract + // the log message. + mockLogger + .Setup(logger => logger.Log(It.IsAny(), 0, It.IsAny(), null, It.IsAny>())) + .Callback((LogLevel logLevel, EventId eventId, object state, Exception exception, Func formatter) => + { + logMessages.Add(state.ToString()); + }); + + return (mockLogger, logMessages); + } + + private static Mock CreateMockConfiguration(string maxChangesPerWorker = null) + { + // GetValue is an extension (static) method and cannot be mocked. However, it calls GetSection which + // expects us to return IConfigurationSection, which is why GetSection is mocked. + var mockConfiguration = new Mock(); + mockConfiguration + .Setup(x => x.GetSection("Sql_Trigger_MaxChangesPerWorker")) + .Returns(Mock.Of(section => section.Value == maxChangesPerWorker)); + + return mockConfiguration; + } + } +} \ No newline at end of file