Msphpsql: [Microsoft][ODBC Driver 17 for SQL Server]Encryption not supported on the client

[mbiebl]

## PHP Driver version or file name

5.8.0 (php_pdo_sqlsrv_74_nts_x86.dll)

SQL Server version

Azure SQL

Client operating system

Windows Server, using IIS/fastcgi

PHP version

7.4.9 (x86, NTS)

## Microsoft ODBC Driver version

2017.175.02.01

Problem description

Our software is based on SabreDAV [1], running on Windows/IIS.
When using SQLExpress as backend, everything is working fine. As soon as we start using AzureSQL, we encounter the following error from time to time. This is from the PHP error log:

[24-Aug-2020 19:17:38 UTC] Failure while creating PDO context:SQLSTATE[08001]: [Microsoft][ODBC Driver 17 for SQL Server]Encryption not supported on the client.

[24-Aug-2020 19:17:38 UTC] PHP Fatal error:  Uncaught PDOException: SQLSTATE[08001]: [Microsoft][ODBC Driver 17 for SQL Server]Encryption not supported on the client. in ..\web\server.php:93

We tried to narrow down the problem.
Our findings so far:

• It only happens with AzureSQL, but not SQLExpress
• It doesn't happen always, but once the php-cgi.exe process gets into this (broken) state, it will trigger the error on every request. This continues until IIS decides to recycle the php-cgi.exe process.
  Sometimes, the server runs a couple of days without triggering the failure, sometimes the failure happens a couple of times per day.
• Using MultipleActiveResultSets=false we can mitigate this failure.

We are quite puzzled at this point and would appreciate any help in further investigating this failure.

[1] https://sabre.io/

[yitam]

Hi @mbiebl the details in your report are much appreciated, and we have more questions:

1. You mentioned about turning off MARS could mitigate this issue. Is this consistent? Or the problem happens less frequently?
2. Where in your php script does this happen? Making connection to AzureSQL?
3. What's your typical connection string? Please use fake credentials.
4. Is it possible to provide ODBC trace up to the point of failure?
5. Have you tried other previous or latest ODBC drivers?

If you're going to provide an ODBC trace, you'll need to modify your pdo_sqlsrv script by adding TraceOn=1;, like this:

$conn = new PDO('sqlsrv:Server=xxx.xxx.xxx.xxx;TraceOn=1;Database=myDB', 'myID', 'myPwd');

To help us investigate or reproduce this issue, we welcome any additional repro scenario and/or steps.

[mbiebl]

Hi @yitam, thanks for your reply.

Hi @mbiebl the details in your report are much appreciated, and we have more questions:

1. You mentioned about turning off MARS could mitigate this issue. Is this consistent? Or the problem happens less frequently?

We had customers who reported this problem to us, so I tried to reproduce the issue inside a Windows VM on Azure.
The tests ran for several weeks. With MARS turned off, we didn't hit the problem anymore. With MARS enabled it usually took at most a day or two before such an error happened (we put the server under load using a jmeter test).
Now, this could be very much specific to my test scenario, but at least there the results were consistent.

1. Where in your php script does this happen? Making connection to AzureSQL?

The error/exception was triggered when instantiating the PDO object right at the beginning of the application, i.e. at the $pdo = new \PDO($db_dsn, $db_login, $db_pass); line:

$db_dsn = 'sqlsrv:Server='.$db_host.';Database='.$db_name;

try {
    $pdo = new \PDO($db_dsn, $db_login, $db_pass);
    $pdo->setAttribute(PDO::ATTR_ERRMODE, PDO::ERRMODE_EXCEPTION);
} catch(PDOException $e) {
    error_log("Failure while creating PDO context:" . $e->getMessage());
    // Set HTTP response to 503: Service Unavailable
    http_response_code(503);
    // Generate a new exception which strips off the stack trace, as the stack
    // trace contains the login data and we don't want to log/show that information.
    throw new \PDOException($e->getMessage());
}

1. What's your typical connection string? Please use fake credentials.

See above

1. Is it possible to provide ODBC trace up to the point of failure?
2. Have you tried other previous or latest ODBC drivers?

If you're going to provide an ODBC trace, you'll need to modify your pdo_sqlsrv script by adding TraceOn=1;, like this:

$conn = new PDO('sqlsrv:Server=xxx.xxx.xxx.xxx;TraceOn=1;Database=myDB', 'myID', 'myPwd');

To help us investigate or reproduce this issue, we welcome any additional repro scenario and/or steps.

I tried ODBC tracing via TraceOn=1, but wasn't able to gather anything (meaningful). I suspect because the error already happens when the PDO object is created. At least I didn't find anything relevant in the PHP log.

[yitam]

Thanks @mbiebl for the prompt response.

when instantiating the PDO object

Yes that's when the driver attempts to make a connection.

We had customers who reported this problem to us, so I tried to reproduce the issue inside a Windows VM on Azure.
The tests ran for several weeks. With MARS turned off, we didn't hit the problem anymore. With MARS enabled it usually took at most a day or two before such an error happened (we put the server under load using a jmeter test).
Now, this could be very much specific to my test scenario, but at least there the results were consistent.

Do you connect to a SQL Server instance in that Windows VM on Azure or do you connect to an Azure SQL Server (also known as SQL Server on Azure)?
Thanks for the php script. Once you have connected, do you disconnect (exit the script, for example)?
Is it the same script you run again and again in a loop? Does the script do anything else?

At any rate, please provide additional details of your test scenario, if possible. Thanks!

[mbiebl]

Do you connect to a SQL Server instance in that Windows VM on Azure or do you connect to an Azure SQL Server (also known as SQL Server on Azure)?

The latter. The problem only happens with an Azure SQL Server

[mbiebl]

Thanks for the php script. Once you have connected, do you disconnect (exit the script, for example)?
Is it the same script you run again and again in a loop? Does the script do anything else?

The application is based on SabreDAV (unfortunately I can't easily share it).
But https://github.com/sabre-io/dav/blob/master/examples/addressbookserver.php should give you an idea.
Instead of sqlite, we use sqlsrv

[mbiebl]

The VM is currently down, which means I'll have to wait until I can run further diagnostics.
Besides the ODBC tracing, is there something else which you would want me to try?

[yitam]

Thanks @mbiebl , yes odbc trace please. Also, if possible, test with a couple of different versions of ODBC driver. We want to know if this problem was introduced lately or already fixed.

The error/exception was triggered when instantiating the PDO object right at the beginning of the application

During your investigation, how often did you instantiate the PDO object in your application?

[mbiebl]

Do you expect this to be a problem in the ODBC driver or in php_pdo_sqlsrv_74_nts_x86.dll?

[mbiebl]

I turned on Trace=1 and now get file C:\Windows\Temp\SQL.LOG
The load test is only running for half an hour and this file is already 100M in size. I'm not sure if I can keep tracing enabled and hitting the error before filling up the hard disk.
I don't see a time stamp in the trace log, here is an excerpt:

php-cgi         202c-14f4       ENTER SQLAllocHandle
                SQLSMALLINT                  2 <SQL_HANDLE_DBC>
                SQLHANDLE           0x0F5B5B48
                SQLHANDLE *         0x071FB998

php-cgi         202c-14f4       EXIT  SQLAllocHandle  with return code 0 (SQL_SUCCESS)
                SQLSMALLINT                  2 <SQL_HANDLE_DBC>
                SQLHANDLE           0x0F5B5B48
                SQLHANDLE *         0x071FB998 ( 0x0F5B5CC8)

php-cgi         202c-14f4       ENTER SQLSetConnectAttr
                SQLHDBC             0x0F5B5CC8
                SQLINTEGER                 104 <SQL_ATTR_TRACE>
                SQLPOINTER                 1 <SQL_OPT_TRACE_ON>
                SQLINTEGER                  -5

php-cgi         202c-14f4       EXIT  SQLSetConnectAttr  with return code 0 (SQL_SUCCESS)
                SQLHDBC             0x0F5B5CC8
                SQLINTEGER                 104 <SQL_ATTR_TRACE>
                SQLPOINTER                 1 <SQL_OPT_TRACE_ON>
                SQLINTEGER                  -5

php-cgi         202c-14f4       ENTER SQLDriverConnectW
                HDBC                0x0F5B5CC8
                HWND                0x00000000
                WCHAR *             0x72F82430 [      -3] "******\ 0"
                SWORD                       -3
                WCHAR *             0x72F82430
                SWORD                       -3
                SWORD *             0x00000000
                UWORD                        0 <SQL_DRIVER_NOPROMPT>

php-cgi         202c-14f4       EXIT  SQLDriverConnectW  with return code 0 (SQL_SUCCESS)
                HDBC                0x0F5B5CC8
                HWND                0x00000000
                WCHAR *             0x72F82430 [      -3] "******\ 0"
                SWORD                       -3
                WCHAR *             0x72F82430 <Invalid buffer length!> [-3]
                SWORD                       -3
                SWORD *             0x00000000
                UWORD                        0 <SQL_DRIVER_NOPROMPT>

Will it be possible to find the needle in the haystack without something like a timestamp?
Would it be possible to filter the trace relevant data only?

[mbiebl]

I also have the problem, that with tracing enabled, I now get:

[30-Nov-2020 17:24:15 UTC] PHP Fatal error:  Maximum execution time of 300 seconds exceeded in C:\Program Files\XXX\vendor\sabre\dav\lib\CardDAV\Backend\PDO.php on line 224

[yitam]

Hi @mbiebl, your inputs are greatly appreciated.

How often do you connect in your application? If possible, periodically turn on/off the tracing (set TraceOn=1 or TraceOn=0) whenever a connection is made. When the problem does not occur, delete the logfile and then resume the tracing.

The keyword is TraceOn. Just to make sure. When the error Encryption not supported on the client resurfaces, you can stop the tracing and send us that log.

Do you expect this to be a problem in the ODBC driver or in php_pdo_sqlsrv_74_nts_x86.dll?

More likely ODBC driver as you said turning off MARS the problem seems to be mitigated. We also have reports from elsewhere that this problem did not seem to happen with an older version of ODBC driver (e.g. 17.1) but so far we can not reproduce this on our side at all.

[mbiebl]

The keyword is TraceOn. Just to make sure.

Yeah, sorry for the typo and the confusion. TraceOn=1 is what I used.

[mbiebl]

How often do you connect in your application?

I create the PDO object at the start of script and then use it througout the request.
The load test simulates 20 concurrent users who each trigger several HTTP requests (~900). Each user does that 5times. So it's about 9000 requests per test run.
The test itself is run every 15 mins, which makes this about 36000 requests / hour.

[yitam]

Thanks again @mbiebl for the additional info. Did you use ApacheBench for simulating 20 concurrent users making various requests every 15 mins or so?

[mbiebl]

we use jmeter: https://jmeter.apache.org/

[mbiebl]

@yitam I really appreciate your help so far. I imagine it must be rather frustrating that I can't provide anything more specific and a better reproducer.
So far, the best we could come up with is to hammer our server with requests until the problem happens. Typically, this happens within a couple of days. It's not easy to reproduce, but eventually it seems to happen.

[yitam]

@mbiebl you actually gave us a sliver of hope. ;) Your inputs have provided more details than we had before, so we might be able to reproduce the issue for further investigation.

[mbiebl]

SQL.LOG.txt

Attached is a trace log showing the problem (ODBC is at version 17.5.2).

I'm now testing 17.6.1

[mbiebl]

Here's a trace log with ODBC version 17.6.1 being installed:
SQL.LOG-17.6.1.txt

[yitam]

Thank you @mbiebl for your contributions! We will investigate and get back to you.

[mbiebl]

I've now also upgraded PHP to version 7.4.13 and also tested the x64 NTS build, but it didn't make a difference. The issue is still reproducible

[yitam]

Thanks @mbiebl we are trying to reproduce this using the latest 7.4.13 but so far nothing yet. Have you been able to reproduce without using SabreDAV? At any rate, what are the typical steps in your script after successfully connecting? Any insert or update or just simple fetching?

[mbiebl]

Basically only fetching:

$ grep pdo  -R
CardDAV/Backend/PDO.php:     * @param \PDO $pdo DB context
CardDAV/Backend/PDO.php:    public function __construct(\PDO $pdo,
CardDAV/Backend/PDO.php:        parent::__construct($pdo);
CardDAV/Backend/PDO.php:        $stmt = $this->pdo->prepare('SELECT principaluri FROM ' . $this->addressBooksTableName . ' WHERE id = ?');
CardDAV/Backend/PDO.php:        $stmt2 = $this->pdo->prepare('SELECT subject, permissions FROM permissions WHERE addressbookid = ?');
CardDAV/Backend/PDO.php:        if (strcasecmp($this->pdo->getAttribute(constant('PDO::ATTR_DRIVER_NAME')), 'sqlsrv') == 0) {
CardDAV/Backend/PDO.php:            $stmt = $this->pdo->prepare('SELECT TOP 1 id, carddata, uri, lastmodified, etag, size FROM ' . $this->cardsTableName . ' WHERE addressbookid = ? AND uri = ?');
CardDAV/Backend/PDO.php:            $stmt = $this->pdo->prepare('SELECT id, carddata, uri, lastmodified, etag, size FROM ' . $this->cardsTableName . ' WHERE addressbookid = ? AND uri = ? LIMIT 1');
CardDAV/Backend/PDO.php:        $stmt = $this->pdo->prepare('SELECT id, uri, displayname, principaluri, description, synctoken FROM ' . $this->addressBooksTableName . ' WHERE principaluri = ?');
CardDAV/Backend/PDO.php:        $shared = $this->pdo->prepare('SELECT id, uri, displayname, principaluri, description, synctoken FROM ' . $this->addressBooksTableName . ' WHERE shared = 1');
AD.php:    private $pdo = null;
AD.php:    function __construct(\PDO $pdo, $settingsTableName = 'systemsettings', $index = 1) {
AD.php:        $this->pdo = $pdo;
AD.php:        $stmt = $this->pdo->prepare('SELECT domainController, domainName, baseDN, directoryType, domainControllerUseSSL FROM ' . $settingsTableName . ' WHERE OID = ?');

i.e. nothing fancy

[yitam]

Hi @mbiebl, so far we are unable to reproduce the issue, despite having tried in different VMs for days, including a Windows 10 VM on Azure, all connecting to an Azure SQL Database and running some queries.

Perhaps you can tell us the specs of your Windows VM on Azure, in particular OS, CPU, memory size, etc.
Also, is the VM in the same location as the Azure SQL Server? In our test case they are both in West US 2.

[mbiebl]

* VM Details *
VM-Type: Standard_B2s
OS: Windows 2019 Datacenter
Availability Zone: westeurope

VM-Template

{
    "$schema": "https://schema.management.azure.com/schemas/2015-01-01/deploymentTemplate.json#",
    "contentVersion": "1.0.0.0",
    "parameters": {
        "extensions_Microsoft_Insights_VMDiagnosticsSettings_xmlCfg": {
            "type": "SecureString"
        },
        "extensions_Microsoft_Insights_VMDiagnosticsSettings_storageAccountName": {
            "type": "SecureString"
        },
        "extensions_Microsoft_Insights_VMDiagnosticsSettings_storageAccountKey": {
            "type": "SecureString"
        },
        "extensions_Microsoft_Insights_VMDiagnosticsSettings_storageAccountEndPoint": {
            "type": "SecureString"
        },
        "virtualMachines_Server01_name": {
            "defaultValue": "Server01",
            "type": "String"
        },
        "disks_Server01_OS_externalid": {
            "defaultValue": "/subscriptions/<subscriptionID>/resourceGroups/Test-West/providers/Microsoft.Compute/disks/Server01_OS",
            "type": "String"
        },
        "networkInterfaces_Server01684_externalid": {
            "defaultValue": "/subscriptions/<subscriptionID>/resourceGroups/Test-West/providers/Microsoft.Network/networkInterfaces/Server01684",
            "type": "String"
        }
    },
    "variables": {},
    "resources": [
        {
            "type": "Microsoft.Compute/virtualMachines",
            "apiVersion": "2019-07-01",
            "name": "[parameters('virtualMachines_Server01_name')]",
            "location": "westeurope",
            "identity": {
                "principalId": "<principalId>",
                "tenantId": "<tenantId>",
                "type": "SystemAssigned"
            },
            "properties": {
                "hardwareProfile": {
                    "vmSize": "Standard_B2s"
                },
                "storageProfile": {
                    "imageReference": {
                        "publisher": "MicrosoftWindowsServer",
                        "offer": "WindowsServer",
                        "sku": "2019-Datacenter",
                        "version": "latest"
                    },
                    "osDisk": {
                        "osType": "Windows",
                        "name": "[concat(parameters('virtualMachines_Server01_name'), '_OS')]",
                        "createOption": "FromImage",
                        "caching": "ReadWrite",
                        "writeAcceleratorEnabled": false,
                        "managedDisk": {
                            "storageAccountType": "StandardSSD_LRS",
                            "id": "[parameters('disks_Server01_OS_externalid')]"
                        },
                        "diskSizeGB": 45
                    },
                    "dataDisks": []
                },
                "osProfile": {
                    "computerName": "[parameters('virtualMachines_Server01_name')]",
                    "adminUsername": "<adminUsername>",
                    "windowsConfiguration": {
                        "provisionVMAgent": true,
                        "enableAutomaticUpdates": true
                    },
                    "secrets": [],
                    "allowExtensionOperations": true,
                    "requireGuestProvisionSignal": true
                },
                "networkProfile": {
                    "networkInterfaces": [
                        {
                            "id": "[parameters('networkInterfaces_Server01684_externalid')]"
                        }
                    ]
                },
                "diagnosticsProfile": {
                    "bootDiagnostics": {
                        "enabled": true
                    }
                }
            }
        },
        {
            "type": "Microsoft.Compute/virtualMachines/extensions",
            "apiVersion": "2019-07-01",
            "name": "[concat(parameters('virtualMachines_Server01_name'), '/AzureNetworkWatcherExtension')]",
            "location": "westeurope",
            "dependsOn": [
                "[resourceId('Microsoft.Compute/virtualMachines', parameters('virtualMachines_Server01_name'))]"
            ],
            "properties": {
                "autoUpgradeMinorVersion": true,
                "publisher": "Microsoft.Azure.NetworkWatcher",
                "type": "NetworkWatcherAgentWindows",
                "typeHandlerVersion": "1.4"
            }
        },
        {
            "type": "Microsoft.Compute/virtualMachines/extensions",
            "apiVersion": "2019-07-01",
            "name": "[concat(parameters('virtualMachines_Server01_name'), '/Microsoft.Insights.VMDiagnosticsSettings')]",
            "location": "westeurope",
            "dependsOn": [
                "[resourceId('Microsoft.Compute/virtualMachines', parameters('virtualMachines_Server01_name'))]"
            ],
            "properties": {
                "autoUpgradeMinorVersion": true,
                "publisher": "Microsoft.Azure.Diagnostics",
                "type": "IaaSDiagnostics",
                "typeHandlerVersion": "1.5",
                "settings": {
                    "StorageAccount": "testwestdiag760",
                    "xmlCfg": "[parameters('extensions_Microsoft_Insights_VMDiagnosticsSettings_xmlCfg')]"
                },
                "protectedSettings": {
                    "storageAccountName": "[parameters('extensions_Microsoft_Insights_VMDiagnosticsSettings_storageAccountName')]",
                    "storageAccountKey": "[parameters('extensions_Microsoft_Insights_VMDiagnosticsSettings_storageAccountKey')]",
                    "storageAccountEndPoint": "[parameters('extensions_Microsoft_Insights_VMDiagnosticsSettings_storageAccountEndPoint')]"
                }
            }
        }
    ]
}

* SQL Server *

Availability Zone: westeurope
Pricing Tier: Standard S0: 10 DTUs

{
    "$schema": "https://schema.management.azure.com/schemas/2015-01-01/deploymentTemplate.json#",
    "contentVersion": "1.0.0.0",
    "parameters": {},
    "variables": {},
    "resources": [
        {
            "type": "Microsoft.Sql/servers",
            "apiVersion": "2019-06-01-preview",
            "name": "Server01-test",
            "location": "westeurope",
            "kind": "v12.0",
            "properties": {
                "administratorLogin": "<administratorLogin>",
                "version": "12.0",
                "publicNetworkAccess": "Enabled"
            }
        },
        {
            "type": "Microsoft.Sql/servers/databases",
            "apiVersion": "2020-08-01-preview",
            "name": "Server01-test/PS-Test",
            "location": "westeurope",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "sku": {
                "name": "Standard",
                "tier": "Standard",
                "capacity": 10
            },
            "kind": "v12.0,user",
            "properties": {
                "collation": "SQL_Latin1_General_CP1_CI_AS",
                "maxSizeBytes": 1073741824,
                "catalogCollation": "SQL_Latin1_General_CP1_CI_AS",
                "zoneRedundant": false,
                "readScale": "Disabled",
                "storageAccountType": "GRS"
            }
        },
        {
            "type": "Microsoft.Sql/servers/databases/geoBackupPolicies",
            "apiVersion": "2014-04-01",
            "name": "Server01-test/master/Default",
            "location": "West Europe",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "state": "Enabled"
            }
        },
        {
            "type": "Microsoft.Sql/servers/databases/transparentDataEncryption",
            "apiVersion": "2014-04-01",
            "name": "Server01-test/master/current",
            "location": "West Europe",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "status": "Disabled"
            }
        },
        {
            "type": "Microsoft.Sql/servers/encryptionProtector",
            "apiVersion": "2015-05-01-preview",
            "name": "Server01-test/current",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "kind": "servicemanaged",
            "properties": {
                "serverKeyName": "ServiceManaged",
                "serverKeyType": "ServiceManaged"
            }
        },
        {
            "type": "Microsoft.Sql/servers/firewallRules",
            "apiVersion": "2015-05-01-preview",
            "name": "Server01-test/ClientIPAddress_2020-09-14_07:34:07",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "startIpAddress": "89.247.39.59",
                "endIpAddress": "89.247.39.59"
            }
        },
        {
            "type": "Microsoft.Sql/servers/firewallRules",
            "apiVersion": "2015-05-01-preview",
            "name": "Server01-test/ClientIPAddress_2020-09-21_12:25:20",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "startIpAddress": "89.244.187.240",
                "endIpAddress": "89.244.187.240"
            }
        },
        {
            "type": "Microsoft.Sql/servers/firewallRules",
            "apiVersion": "2015-05-01-preview",
            "name": "Server01-test/ClientIPAddress_2020-10-05_03:57:44",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "startIpAddress": "88.130.77.58",
                "endIpAddress": "88.130.77.58"
            }
        },
        {
            "type": "Microsoft.Sql/servers/firewallRules",
            "apiVersion": "2015-05-01-preview",
            "name": "Server01-test/ClientIPAddress_2020-8-26_13-10-39",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "startIpAddress": "46.114.34.101",
                "endIpAddress": "46.114.34.101"
            }
        },
        {
            "type": "Microsoft.Sql/servers/keys",
            "apiVersion": "2015-05-01-preview",
            "name": "Server01-test/ServiceManaged",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "kind": "servicemanaged",
            "properties": {
                "serverKeyType": "ServiceManaged"
            }
        },
        {
            "type": "Microsoft.Sql/servers/securityAlertPolicies",
            "apiVersion": "2020-02-02-preview",
            "name": "Server01-test/Default",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "state": "Disabled"
            }
        },
        {
            "type": "Microsoft.Sql/servers/virtualNetworkRules",
            "apiVersion": "2015-05-01-preview",
            "name": "Server01-test/Allow-Test-West-Vnet",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "virtualNetworkSubnetId": "/subscriptions/<subscriptionID>/resourceGroups/Test-West/providers/Microsoft.Network/virtualNetworks/Test-West-vnet/subnets/default",
                "ignoreMissingVnetServiceEndpoint": false
            }
        },
        {
            "type": "Microsoft.Sql/servers/vulnerabilityAssessments",
            "apiVersion": "2018-06-01-preview",
            "name": "Server01-test/Default",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "recurringScans": {
                    "isEnabled": false,
                    "emailSubscriptionAdmins": true
                },
                "storageContainerPath": null
            }
        },
        {
            "type": "Microsoft.Sql/servers/databases/advisors",
            "apiVersion": "2014-04-01",
            "name": "Server01-test/PS-Test/CreateIndex",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers/databases', 'Server01-test', 'PS-Test')]",
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "autoExecuteValue": "Disabled"
            }
        },
        {
            "type": "Microsoft.Sql/servers/databases/advisors",
            "apiVersion": "2014-04-01",
            "name": "Server01-test/PS-Test/DbParameterization",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers/databases', 'Server01-test', 'PS-Test')]",
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "autoExecuteValue": "Disabled"
            }
        },
        {
            "type": "Microsoft.Sql/servers/databases/advisors",
            "apiVersion": "2014-04-01",
            "name": "Server01-test/PS-Test/DefragmentIndex",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers/databases', 'Server01-test', 'PS-Test')]",
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "autoExecuteValue": "Disabled"
            }
        },
        {
            "type": "Microsoft.Sql/servers/databases/advisors",
            "apiVersion": "2014-04-01",
            "name": "Server01-test/PS-Test/DropIndex",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers/databases', 'Server01-test', 'PS-Test')]",
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "autoExecuteValue": "Disabled"
            }
        },
        {
            "type": "Microsoft.Sql/servers/databases/advisors",
            "apiVersion": "2014-04-01",
            "name": "Server01-test/PS-Test/ForceLastGoodPlan",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers/databases', 'Server01-test', 'PS-Test')]",
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "autoExecuteValue": "Enabled"
            }
        },
        {
            "type": "Microsoft.Sql/servers/databases/auditingPolicies",
            "apiVersion": "2014-04-01",
            "name": "Server01-test/PS-Test/Default",
            "location": "West Europe",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers/databases', 'Server01-test', 'PS-Test')]",
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "auditingState": "Disabled"
            }
        },
        {
            "type": "Microsoft.Sql/servers/databases/auditingSettings",
            "apiVersion": "2017-03-01-preview",
            "name": "Server01-test/PS-Test/Default",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers/databases', 'Server01-test', 'PS-Test')]",
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "retentionDays": 0,
                "auditActionsAndGroups": [
                    "SUCCESSFUL_DATABASE_AUTHENTICATION_GROUP",
                    "FAILED_DATABASE_AUTHENTICATION_GROUP",
                    "BATCH_COMPLETED_GROUP"
                ],
                "isStorageSecondaryKeyInUse": false,
                "isAzureMonitorTargetEnabled": true,
                "state": "Disabled",
                "storageAccountSubscriptionId": "00000000-0000-0000-0000-000000000000"
            }
        },
        {
            "type": "Microsoft.Sql/servers/databases/backupLongTermRetentionPolicies",
            "apiVersion": "2017-03-01-preview",
            "name": "Server01-test/PS-Test/default",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers/databases', 'Server01-test', 'PS-Test')]",
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "weeklyRetention": "PT0S",
                "monthlyRetention": "PT0S",
                "yearlyRetention": "PT0S",
                "weekOfYear": 0
            }
        },
        {
            "type": "Microsoft.Sql/servers/databases/backupShortTermRetentionPolicies",
            "apiVersion": "2017-10-01-preview",
            "name": "Server01-test/PS-Test/default",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers/databases', 'Server01-test', 'PS-Test')]",
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "retentionDays": 7
            }
        },
        {
            "type": "Microsoft.Sql/servers/databases/extendedAuditingSettings",
            "apiVersion": "2017-03-01-preview",
            "name": "Server01-test/PS-Test/Default",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers/databases', 'Server01-test', 'PS-Test')]",
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "retentionDays": 0,
                "auditActionsAndGroups": [
                    "SUCCESSFUL_DATABASE_AUTHENTICATION_GROUP",
                    "FAILED_DATABASE_AUTHENTICATION_GROUP",
                    "BATCH_COMPLETED_GROUP"
                ],
                "isStorageSecondaryKeyInUse": false,
                "isAzureMonitorTargetEnabled": true,
                "state": "Disabled",
                "storageAccountSubscriptionId": "00000000-0000-0000-0000-000000000000"
            }
        },
        {
            "type": "Microsoft.Sql/servers/databases/geoBackupPolicies",
            "apiVersion": "2014-04-01",
            "name": "Server01-test/PS-Test/Default",
            "location": "West Europe",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers/databases', 'Server01-test', 'PS-Test')]",
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "state": "Enabled"
            }
        },
        {
            "type": "Microsoft.Sql/servers/databases/securityAlertPolicies",
            "apiVersion": "2020-02-02-preview",
            "name": "Server01-test/PS-Test/Default",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers/databases', 'Server01-test', 'PS-Test')]",
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "state": "Disabled"
            }
        },
        {
            "type": "Microsoft.Sql/servers/databases/transparentDataEncryption",
            "apiVersion": "2014-04-01",
            "name": "Server01-test/PS-Test/current",
            "location": "West Europe",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers/databases', 'Server01-test', 'PS-Test')]",
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "status": "Enabled"
            }
        },
        {
            "type": "Microsoft.Sql/servers/databases/vulnerabilityAssessments",
            "apiVersion": "2017-03-01-preview",
            "name": "Server01-test/PS-Test/Default",
            "dependsOn": [
                "[resourceId('Microsoft.Sql/servers/databases', 'Server01-test', 'PS-Test')]",
                "[resourceId('Microsoft.Sql/servers', 'Server01-test')]"
            ],
            "properties": {
                "recurringScans": {
                    "isEnabled": false,
                    "emailSubscriptionAdmins": true
                }
            }
        }
    ]
}

[yitam]

Thank you @mbiebl !
I was going to inform you that we could finally reproduce the problem now. We will continue investigating.

[mbiebl]

This is great news!

[ajdjackson]

Hi @yitam. Any update on this issue?
I'm experiencing the same issue. I'm connect from an Azure Windows Windows 2019 server VM, using PHP 7.4 and OBDC Driver 17 for SQL Server 2017.176.01.1 to an Azure SQL Database.
As mbiebl I'm getting the same random connectivity failures. I then perform an IIS Reset to recover.
I would like to make my application live but I'm nervous that when I add users the frequency of the issue will increase.

Many thanks

[yitam]

Yes @ajdjackson we could reproduce this in the test lab, as I have told @mbiebl earlier. However, not only it takes time to reproduce, but it's also intermittent and unpredictable. Investigation will not be straightforward but we are working to get to the bottom of this.

Yet, as @mbiebl mentioned, it seems turning off MARS may be a workaround. If you experience otherwise or have anything else to share to help us reproduce this issue, please let us know at your earliest convenience.

[mbiebl]

Thanks for the php script. Once you have connected, do you disconnect (exit the script, for example)?
Is it the same script you run again and again in a loop? Does the script do anything else?

The application is based on SabreDAV (unfortunately I can't easily share it).
But https://github.com/sabre-io/dav/blob/master/examples/addressbookserver.php should give you an idea.
Instead of sqlite, we use sqlsrv

Btw, since I couldn't share the original PHP application where we hit this issue, I tried to reproduce it with a barebones sabre-dav server and was successful. So I could share a zip file containing the PHP files and the SQL database now and then you just need to hammer the server with requests (I can probably share the jmeter test we used as well).
But since @yitam mentioned that they were able to reproduce the issue, I figured this was no longer relevant.
And yes, the issue is sporadic and not happening often. But it does happen eventually.

[yitam]

Thank you @mbiebl for the additional info. Yes, continuously hammering the server with requests for at least two days (sometimes longer) is what we do to reproduce this issue.

[mbiebl]

Yes, continuously hammering the server with requests for at least two days (sometimes longer) is what we do to reproduce this issue.

Yep, this matches my experience

[yitam]

Hi @mbiebl and @ajdjackson, here is an update: we figured out a way to consistently reproduce the issue and found the underlying causes at long last. We are running different tests, including stress testing the server, to make sure the fix in the ODBC driver does not introduce regressions.

[ajdjackson]

Hi @yitam
Thanks for the update.
I've had no further connection issues since turning MARS off.
Thanks
Jake

[woduda]

@yitam Could you confirm that the issue has something in common with the MARS turned on and that's why we should turn it off on production servers to mitigate? I'm asking because we need to decide if wait for ODBC final fix or apply the workaround. Thanks.

[yitam]

To answer your question @woduda , with MARS turned on it takes longer to connect or disconnect, thus opening a larger window for some race conditions that are causing this particular issue. It's not necessarily a workaround, but if you're not planning to use MARS we would suggest you turn it off entirely.

FYI, ODBC team is working on a hotfix for the time being but there's no fixed date yet.

[trondvo]

I am happy to hear this has been identified and being fixed. We have had this problem ever since late 2019 if I remember correct.
We have tried running on Windows server 2012, 2016, 2019 (Azure VPS and Azure Sql server), older version PHP with older PHP driver, even ODBC driver 13 but no luck, every few hours the "encryption not supported..." error would occur. Status PHP.exe possibly crashing but the .NET code still would run.

Restart IIS and it would be fine for a few hours or sometimes just minutes, very random. We run same PHP application on Linux with Apache server as well, never any problems. Now running MARS = false and the problem is gone.

[yitam]

Hi all, ODBC Driver 17.7.2 is available for download now. Please give it a try and let us know how it goes.

[mbiebl]

@yitam I've been running our load test for a day now (with MARS enabled) and 17.7.2.1. Looking good so far!
Will keep it running for another week and keep you posted.
Thanks a lot @yitam !

[lwohlhart]

For everyone who is as confused as I was: Make sure you hit the english version of the ODBC Driver download page
https://docs.microsoft.com/en-us/sql/connect/odbc/download-odbc-driver-for-sql-server?view=sql-server-ver15
(in my case the german version still only offers 17.7.1)

[David-Engel]

@lwohlhart

There is a delay between when the English docs are updated for a release and when the localized pages get updated by the localization process. I don’t know what the typical lag is, but that’s the reason for this note on the download pages:

Regards,
David

[mbiebl]

@yitam load test has been running for a week now without a hitch.
I guess we can consider this issue fixed.

[yitam]

Awesome! Thanks @mbiebl 👍 Please let us know if it reappears.