EndExecuteReader ignoring CommandTimeout

[trentin]

I have upgraded from 3.75 to 4.95 and now EndExecuteReader always times out after 30 seconds regardless of the CommandTimeout setting.

Here is the code that has stopped working:

Code: Select all

    Sub execute_script()
        Using script As New PgSqlDataTable("select id,script,fail_ok from version_script where version_id>(select max(version.id) from version) or version_id=0 order by version_id,id", conn)
            script.Fill()
            ProgressBarControl.EditValue = 0
            Dim i As Int64 = 0
            Using sql As New PgSqlCommand() With {.CommandTimeout = 0, .Connection = conn, .CommandText = "utils.execute_script", .CommandType = CommandType.StoredProcedure}
                sql.Parameters.Add("in_script_id", PgSqlType.BigInt)
                sql.Parameters.Add("in_script", PgSqlType.Text)
                sql.Parameters.Add("in_fail_ok", PgSqlType.Boolean)
                sql.Prepare()
                For Each row As DataRow In script.Rows
                    sql.Parameters("in_script_id").Value = row("id")
                    sql.Parameters("in_script").Value = row("script")
                    sql.Parameters("in_fail_ok").Value = row("fail_ok")
                    Dim ar As IAsyncResult = sql.BeginExecuteReader()
                    i += 1
                    ProgressBarControl.EditValue = i / script.Rows.Count * 100
                    ExecutingMemoEdit.Text = ""
                    Application.DoEvents()
                    If Not ar.IsCompleted Then
                        ExecutingMemoEdit.Text = row("script")
                    End If
                    While Not ar.IsCompleted
                        Application.DoEvents()
                    End While
                    Dim reader As PgSqlDataReader = sql.EndExecuteReader(ar)
                    While reader.Read
                        If Not reader.GetString(0) = "OK" Then
                            Log.Text &= row("id") & ": " & row("script") & vbCrLf
                            Log.Text &= reader.GetString(0) & vbCrLf
                        End If
                    End While
                    reader.Close()
                Next
            End Using
        End Using
    End Sub

This is the exception that EndExecuteReader throws:

Code: Select all

Devart.Data.PostgreSql.PgSqlException was unhandled
  ErrorCode=08006
  ErrorCode (ExternalException)=-2147467259
  LineNumber=0
  Message=Server did not respond within the specified timeout interval.
  Position=0
  Source=mscorlib
  StackTrace:
    Server stack trace: 
       at Devart.Data.PostgreSql.PgSqlDataReader.e(Int32 A_0)
       at Devart.Data.PostgreSql.PgSqlCommand.InternalExecute(CommandBehavior behavior, IDisposable stmt, Int32 startRecord, Int32 maxRecords)
       at Devart.Common.DbCommandBase.ExecuteDbDataReader(CommandBehavior behavior, Boolean nonQuery)
       at Devart.Common.DbCommandBase.AsyncExecuteReader(CommandBehavior behavior)
       at System.Runtime.Remoting.Messaging.StackBuilderSink._PrivateProcessMessage(IntPtr md, Object[] args, Object server, Int32 methodPtr, Boolean fExecuteInContext, Object[]& outArgs)
       at System.Runtime.Remoting.Messaging.StackBuilderSink.PrivateProcessMessage(RuntimeMethodHandle md, Object[] args, Object server, Int32 methodPtr, Boolean fExecuteInContext, Object[]& outArgs)
       at System.Runtime.Remoting.Messaging.StackBuilderSink.AsyncProcessMessage(IMessage msg, IMessageSink replySink)
    Exception rethrown at [0]: 
       at System.Runtime.Remoting.Proxies.RealProxy.EndInvokeHelper(Message reqMsg, Boolean bProxyCase)
       at System.Runtime.Remoting.Proxies.RemotingProxy.Invoke(Object NotUsed, MessageData& msgData)
       at Devart.Common.DbCommandBase.a.EndInvoke(IAsyncResult A_0)
       at Devart.Common.DbCommandBase.EndExecuteReader(IAsyncResult result)
       at Devart.Data.PostgreSql.PgSqlCommand.EndExecuteReader(IAsyncResult result)
       at Dolphin.dbUpgradeForm.execute_script() in C:\Users\Tobie\Documents\Visual Studio 2010\Projects\dolphin\trunk\Estimating\Utils\dbUpgradeForm.vb:line 60
       at Dolphin.dbUpgradeForm.Upgrade() in C:\Users\Tobie\Documents\Visual Studio 2010\Projects\dolphin\trunk\Estimating\Utils\dbUpgradeForm.vb:line 121
       at Dolphin.loginForm.OKButton_Click(Object sender, EventArgs e) in C:\Users\Tobie\Documents\Visual Studio 2010\Projects\dolphin\trunk\Estimating\loginForm.vb:line 114
       at DevExpress.XtraEditors.BaseButton.OnClick(EventArgs e)
       at DevExpress.XtraEditors.BaseButton.OnMouseUp(MouseEventArgs e)
       at System.Windows.Forms.Control.WmMouseUp(Message& m, MouseButtons button, Int32 clicks)
       at System.Windows.Forms.Control.WndProc(Message& m)
       at DevExpress.Utils.Controls.ControlBase.WndProc(Message& m)
       at System.Windows.Forms.NativeWindow.DebuggableCallback(IntPtr hWnd, Int32 msg, IntPtr wparam, IntPtr lparam)
       at System.Windows.Forms.UnsafeNativeMethods.DispatchMessageW(MSG& msg)
       at System.Windows.Forms.Application.ComponentManager.System.Windows.Forms.UnsafeNativeMethods.IMsoComponentManager.FPushMessageLoop(IntPtr dwComponentID, Int32 reason, Int32 pvLoopData)
       at System.Windows.Forms.Application.ThreadContext.RunMessageLoopInner(Int32 reason, ApplicationContext context)
       at System.Windows.Forms.Application.ThreadContext.RunMessageLoop(Int32 reason, ApplicationContext context)
       at Microsoft.VisualBasic.ApplicationServices.WindowsFormsApplicationBase.OnRun()
       at Microsoft.VisualBasic.ApplicationServices.WindowsFormsApplicationBase.DoApplicationModel()
       at Microsoft.VisualBasic.ApplicationServices.WindowsFormsApplicationBase.Run(String[] commandLine)
       at Dolphin.My.MyApplication.Main(String[] Args) in 17d14f5c-a337-4978-8281-53493378c1071.vb:line 81
       at System.AppDomain._nExecuteAssembly(RuntimeAssembly assembly, String[] args)
       at System.Runtime.Hosting.ApplicationActivator.CreateInstance(ActivationContext activationContext, String[] activationCustomData)
       at Microsoft.VisualStudio.HostingProcess.HostProc.RunUsersAssemblyDebugInZone()
       at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean ignoreSyncCtx)
       at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
       at System.Threading.ThreadHelper.ThreadStart()
  InnerException: System.TimeoutException
       Message=Server did not respond within the specified timeout interval.
       Source=Devart.Data.PostgreSql
       StackTrace:
            at Devart.Common.ac.a(Byte[] A_0, Int32 A_1, Int32 A_2)
            at Devart.Common.d.c(Byte[] A_0, Int32 A_1, Int32 A_2)
            at Devart.Common.n.e(Byte[] A_0, Int32 A_1, Int32 A_2)
       InnerException: System.IO.IOException
            Message=Unable to read data from the transport connection: A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond.
            Source=System
            StackTrace:
                 at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
                 at Devart.Common.ac.a(Byte[] A_0, Int32 A_1, Int32 A_2)
            InnerException: System.Net.Sockets.SocketException
                 ErrorCode=10060
                 Message=A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond
                 NativeErrorCode=10060
                 Source=System
                 StackTrace:
                      at System.Net.Sockets.NetworkStream.Read(Byte[] buffer, Int32 offset, Int32 size)
                 InnerException:

[Shalex]

1. I have checked the 4.95.152 build of dotConnect for PostgreSQL. The following code works. Please try it in your environment and notify us about the results:

Code: Select all

        Using conn As New PgSqlConnection()
            conn.ConnectionString = "server=db;port=5437;database=postgres;uid=***;pwd=***;"
            Dim cmd As PgSqlCommand = conn.CreateCommand()
            cmd.CommandTimeout = 0
            cmd.UnpreparedExecute = True
            cmd.CommandText = "select 1; select pg_sleep(40);"
            conn.Open()
            Dim res As IAsyncResult = cmd.BeginExecuteReader()
            Dim reader As PgSqlDataReader = cmd.EndExecuteReader(res)
            reader.Read()
            Dim i As Int16 = Convert.ToInt32(reader(0))
            If (i = 1) Then
                Console.WriteLine("Test is successful!")
            End If
        End Using

2. Also try initializing CommandTimeout via the Default Command Timeout=0; connection string parameter to make sure all command objects that use your connection object have CommandTimeout=0.
3. Tell us your version. You can find it via the Tools > PostgreSQL > About menu of Visual Studio.
4. How should we modify the sample above to reproduce the issue in our environment?

[trentin]

Prepare seems to cause the issue. More precisely reusing a prepared command seems to cause the problem.

If I remove Prepare from my code it works. If I modify your code like this it breaks:

Code: Select all

        Using conn As New PgSqlConnection()
            conn.ConnectionString = "server=localhost;port=5432;database=postgres;uid=***;pwd=***;"
            Dim cmd As PgSqlCommand = conn.CreateCommand()
            cmd.CommandTimeout = 0
            'cmd.UnpreparedExecute = True
            cmd.CommandText = "select 1,pg_sleep(40);"
            conn.Open()
            cmd.Prepare()
            For j As Integer = 1 To 10
                Dim res As IAsyncResult = cmd.BeginExecuteReader()
                While Not res.IsCompleted
                    Console.WriteLine("waiting..." & j)
                    Threading.Thread.Sleep(1000)
                End While
                Dim reader As PgSqlDataReader = cmd.EndExecuteReader(res)
                reader.Read()
                Dim i As Int16 = Convert.ToInt32(reader(0))
                reader.Close()
                If (i = 1) Then
                    Console.WriteLine("Test is successful!")
                Else
                    Console.WriteLine("Test failed!")
                End If
                Console.Clear()
            Next
        End Using

If I remove the cmd.Prepare from this code it works.

[Shalex]

I have reproduced the NRE on the second iteration. Is that what you mean in your previous post?

[Shalex]

I have reproduced the NRE on the second iteration. Is that what you mean in your previous post? We will investigate the issue.

[trentin]

Thanks.

I am satisfied for now, I can use the code without calling Prepare.

[Shalex]

We have fixed the problem. I will post here when the corresponding build is available for download.

[Shalex]

New build of dotConnect for PostgreSQL 4.95.170 is available for download now!
It can be downloaded from http://www.devart.com/dotconnect/postgr ... nload.html (trial version) or from Registered Users' Area (for users with valid subscription only).
For more information, please refer to http://www.devart.com/forums/viewtopic.php?t=19070 .