Azure SQL: Invalid operation. The connection is closed

laupie · September 28, 2022, 12:56pm

Dear fellow easymorph (em) users,

We have an em package, scheduled as task from the server, running every 15 mins,

The reason I reach out to you is…, sometimes we have a strange error.

The step that fails is the ‘import from database’, the database is actually an Azure SQL Database.
The import is just a simple table, around 50k rows.
We did some logging on the database and the load is around 1-4% and there are no heavy queries running at the time our em package fails.

The error produced is:
"
Invalid operation. The connection is closed.
Location: action “Import from database”, module “FinYears”,
"
(We use the default logging from the scheduler.)

This happens only ad random. Mostly in the evening.
Furthermore, at first sight, we can not spot any rarities in the network at the time of the error.

Someone has an idea what can be the problem OR how we can troubleshoot this better ?

Many thanks in advance

dgudkov · September 28, 2022, 4:41pm

Hi Laurens and welcome to the Community!

What’s your EasyMorph version?

laupie · September 28, 2022, 8:24pm

Hi Dmitry,

Thanks! Happy to be a part of it - as of today.

Client version is 5.2.1.10 (5.3 is ready to be installed)
Server version: 5.2.1.7

andrew.rybka · September 30, 2022, 11:21am

Hi Laurens,

Can you please turn on the Diagnostics Log for that task (on the task’s Options tab), wait for the next occurrence of that error, and send the created Diagnostics Log to our support email? Please don’t forget to turn off the Diagnostics Log for that task afterward.

laupie · October 3, 2022, 10:26am

Hi Andrew,

Thanks for your reply. Please find below an extract, the most important part, of the error, taken from the diagnostic log file.
I have sent the full log to the support email address as well.

Just one slight thing we noticed:

Could it be possible easymorph uses the ‘old’ sql dataclient?

The log mentions the ‘System.Data.SqlClient’ whereas the new(est) client is ‘Microsoft.Data.SqlClient’

Thank you.

02/10/2022 XX:15:43    000216            ERROR     Source: action "Import from database", module "Main", table "PREMAP | Extant dbo.Relations"
02/10/2022 XX:15:43    000217            ERROR     
02/10/2022 XX:15:43    000218            ERROR     Exception: 
02/10/2022 XX:15:43    000219            ERROR     InvalidOperationException
02/10/2022 XX:15:43    000220            ERROR     Invalid operation. The connection is closed.
02/10/2022 XX:15:43    000221            ERROR     Call stack:
02/10/2022 XX:15:43    000222            ERROR        at System.Data.SqlClient.TdsParserStateObject.ReadSniSyncOverAsync()
02/10/2022 XX:15:43    000223            ERROR        at System.Data.SqlClient.TdsParserStateObject.TryReadNetworkPacket()
02/10/2022 XX:15:43    000224            ERROR        at System.Data.SqlClient.TdsParserStateObject.TryPrepareBuffer()
02/10/2022 XX:15:43    000225            ERROR        at System.Data.SqlClient.TdsParserStateObject.TryReadUInt32(UInt32& value)
02/10/2022 XX:15:43    000226            ERROR        at System.Data.SqlClient.TdsParserStateObject.TryReadPlpLength(Boolean returnPlpNullIfNull, UInt64& lengthLeft)
02/10/2022 XX:15:43    000227            ERROR        at System.Data.SqlClient.TdsParser.TrySkipPlpValue(UInt64 cb, TdsParserStateObject stateObj, UInt64& totalBytesSkipped)
02/10/2022 XX:15:43    000228            ERROR        at System.Data.SqlClient.TdsParser.TrySkipValue(SqlMetaDataPriv md, Int32 columnOrdinal, TdsParserStateObject stateObj)
02/10/2022 XX:15:43    000229            ERROR        at System.Data.SqlClient.TdsParser.TrySkipRow(_SqlMetaDataSet columns, Int32 startCol, TdsParserStateObject stateObj)
02/10/2022 XX:15:43    000230            ERROR        at System.Data.SqlClient.SqlDataReader.TryCleanPartialRead()
02/10/2022 XX:15:43    000231            ERROR        at System.Data.SqlClient.SqlDataReader.TryReadInternal(Boolean setTimeout, Boolean& more)
02/10/2022 XX:15:43    000232            ERROR        at System.Data.SqlClient.SqlDataReader.Read()
02/10/2022 XX:15:43    000233            ERROR        at Morph.DataDrivers.Database.DataReaders.DataReaderBase._ReadDbRows(DbDataReader reader, CancellationToken cancellationToken)
02/10/2022 XX:15:43    000234            ERROR        at Morph.DataDrivers.Database.DataReaders.DataReaderBase.(DbCommand , String , CancellationToken )
02/10/2022 XX:15:43    000235            ERROR        at Morph.DataDrivers.Database.DataReaders.DataReaderBase.RunQuery(String sql, CancellationToken token)
02/10/2022 XX:15:43    000236            ERROR        at Morph.DataDrivers.Database.DatabaseImportDriver..MoveNext()
02/10/2022 XX:15:43    000237            ERROR     --- End of stack trace from previous location where exception was thrown ---
02/10/2022 XX:15:43    000238            ERROR        at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
02/10/2022 XX:15:43    000239            ERROR        at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
02/10/2022 XX:15:43    000240            ERROR        at Morph.DataDrivers.Database.DatabaseImportDriver..MoveNext()
02/10/2022 XX:15:43    000241            INFO      cleanUp called

Please also consider following resource: Fixes "InvalidOperationException" errors by performing async operations in SemaphoreSlim by cheenamalhotra · Pull Request #796 · dotnet/SqlClient · GitHub

andrew.rybka · October 3, 2022, 6:04pm

Hi Laurens,

Yes, EasyMorph uses System.Data.SqlClient, which quite possibly may be the source of the error in question.

We will test EasyMorph with Microsoft.Data.SqlClient and release an updated version if everything is OK.

laupie · October 3, 2022, 7:53pm

Hi Andrew,

Great to see your alertness.
Glad we could help. Do not hesitate to let me know via this topic or via pm when the new version can be tested (possible through Beta)

Thank you

David · October 23, 2022, 5:01pm

Hello Andrew,

is there any news on this?

Thanks and kind regards

David

andrew.rybka · October 24, 2022, 8:26am

Hello David,

We tested EasyMorph with Microsoft.Data.SqlClient and our test SQL Server. And it seems that everything is OK, so we are planning to switch to that client.

We expect this fix to be released with the next EasyMorph version in 1 or 2 weeks,
but we are still resolving some issues with the new client package, so I can’t make any promises.

David · October 24, 2022, 8:48am

Hello Andrew,

great news, thanks for this. We’re looking forward to the next release then

Kind regards,
David

David · November 9, 2022, 8:37am

Hello @andrew.rybka

Hope you are well.
Could you tell us whether the switch to the Microsoft.Data.SqlClient was implemented in v5.3.1 ? If not, what would be the timeline for the next release? We’re relying more and more on our Azure DB connectors, and this leads to more and more instances of the same ‘Connection is closed’ error. So any improvement on this would be great

David

dgudkov · November 9, 2022, 11:46am

Hi @David,

Yes, it was implemented. Version 5.3.1 was released yesterday.

David · November 9, 2022, 11:50am

Great, thanks! We’ll upgrade asap and will let you know whether the error we encouter(ed) was fixed.

laupie · December 5, 2022, 2:50pm

Hello dgudkov,

We still get the (same) error very often, I fear it hasn’t changed with the recent EasyMorph update:
“Invalid operation. The connection is closed.”

I have attached the log from one of the errors of today.
This is the result of the diagnostic logging on the Server.
EM_DiagnosticLog_20221205_part.txt (4.9 KB)

Is there anything else you can advise us to do ? Thank you in advance.

andrew.rybka · December 5, 2022, 6:38pm

Hello @laupie,

Can you please check if this error always has the same first line of the call stack?

Unfortunately, I haven’t been able to find anything useful on the Internet. Can you please check your Azure SQL server logs for the same period of time?

laupie · December 5, 2022, 8:01pm

Hi Andrew,

Thanks for your reply.

The call stack is always exactly the same (since logging Sept - till now), please check below an example.

We already investigated the Azure SQL server logs as well as the Network logs and couldn’t find any issues there. Please note the Azure SQL server logging is less extensive/comprehensive than SQL on prem.

Unfortunately there is not much to be found on this error on the internet.

01/12/2022 16:18:24 01/12/2022 16:18:24 01/12/2022 16:18:24 01/12/2022 16:18:24 01/12/2022 16:18:24 01/12/2022 16:18:24 01/12/2022 16:18:24 01/12/2022 16:18:24 01/12/2022 16:18:24 01/12/2022 16:18:24 01/12/2022 16:18:24 01/12/2022 16:18:24 01/12/2022 16:18:24 01/12/2022 16:18:24 01/12/2022 16:18:24 01/12/2022 16:18:24 01/12/2022 16:18:24 01/12/2022 16:18:24 01/12/2022 16:18:24 01/12/2022 16:18:24 000102 ERROR Call stack:
000103 ERROR at Microsoft.Data.SqlClient.TdsParserStateObject.ReadSniSyncOverAsync()
000104 ERROR at Microsoft.Data.SqlClient.TdsParserStateObject.TryReadNetworkPacket()
000105 ERROR at Microsoft.Data.SqlClient.TdsParserStateObject.TryPrepareBuffer()
000106 ERROR at Microsoft.Data.SqlClient.TdsParserStateObject.TryReadUInt32(UInt32& value)
000107 ERROR at Microsoft.Data.SqlClient.TdsParserStateObject.TryReadPlpLength(Boolean returnPlpNullIfNull, UInt64& lengthLeft)
000108 ERROR at Microsoft.Data.SqlClient.TdsParser.TrySkipPlpValue(UInt64 cb, TdsParserStateObject stateObj, UInt64& totalBytesSkipped)
000109 ERROR at Microsoft.Data.SqlClient.SqlDataReader.TryResetBlobState()
000110 ERROR at Microsoft.Data.SqlClient.SqlDataReader.TryCleanPartialRead()
000111 ERROR at Microsoft.Data.SqlClient.SqlDataReader.TryReadInternal(Boolean setTimeout, Boolean& more)
000112 ERROR at Microsoft.Data.SqlClient.SqlDataReader.Read()
000113 ERROR at Morph.DataDrivers.Database.DataReaders.DataReaderBase._ReadDbRows(DbDataReader reader, CancellationToken cancellationToken)
000114 ERROR at Morph.DataDrivers.Database.DataReaders.DataReaderBase.(DbCommand , String , CancellationToken )
000115 ERROR at Morph.DataDrivers.Database.DataReaders.DataReaderBase.RunQuery(String sql, CancellationToken token)
000116 ERROR at Morph.DataDrivers.Database.DatabaseImportDriver..MoveNext()
000117 ERROR — End of stack trace from previous location where exception was thrown —
000118 ERROR at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
000119 ERROR at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
000120 ERROR at Morph.DataDrivers.Database.DatabaseImportDriver..MoveNext()
000121 ERROR Error: Calling module “CHECK ID” failed.

andrew.rybka · December 6, 2022, 7:42pm

You can try to file a bug repot with the GitHub - dotnet/SqlClient: Microsoft.Data.SqlClient provides database connectivity to SQL Server for .NET applications. repository.

Justin_Grewe · December 7, 2022, 8:58pm

We are on Azure SQL as well and had to add a few custom parameters in the connection settings in easymorph per connection. Encrypt = false and multisubnetfailover = true. Not sure if that helps you.

laupie · December 8, 2022, 7:59am

Hi Justin, many thanks for your reply! Will test if this make a difference.
(although I need to check what’s the concrete security impact concerning “Encrypt = false”)