[#1010779] Respect CommandTimeout in first function call w/ string parameter

View Trackers | Patches | Download .csv | Monitor

Date:
2010-03-16 07:02 Priority:
3

State:
Open

Submitted by:
Noah Misch (nmisch) Assigned to:
Nobody (None)

Category: Group:

Resolution:
None

Summary:
Respect CommandTimeout in first function call w/ string parameter

Detailed description
When a connection to a server with "standard_conforming_strings = off" first executes a command with a string parameter, we run "SHOW escape_string_warning" internally. That internal command clobbers the user's CommandTimeout for the execution of the main command. The effective CommandTimeout was 20 until NpgsqlCommand.cs revision 1.46 (2010-02-16), and lately 0 (unlimited). This patch adds a CommandTimeout/SqlSent reset to NpgsqlCommand.GetCommandText, the last NpgsqlCommand entry before we use the timeout value in ProcessBackendResponsesEnum. I have removed similar, existing resets in GetCommandText callees. This is a bit of a hack; the right fix seemed to be to push CommandTimeout through the call stack instead of through the mediator, but that wasn't readily satisfying either. Thoughts? I've also added test cases. Related discussion: http://pgfoundry.org/forum/forum.php?thread_id=2514&forum_id=519 Thanks, nm

Followup

Message
Date: 2010-04-08 15:33 Sender: Noah Misch Francisco, Thanks for retesting and applying the patch. I agree, the way timeout handling has touched so many places shows the need for a different strategy. I will put some more thought into that.
Date: 2010-04-06 04:04 Sender: Francisco Figueiredo jr. Hi, Noah! Got it. Sorry for misunderstanding. I thought I had applied your patch, but I didn't. With your tests I could reproduce the problem and applied your patch correctly. At least, with all the other changes, I just had to add the relevant lines to GetCommandText. Also, I'm noticing that this timeout issue is all spread in the code base. If you have suggestions to "clean" this up, they are very welcome. We have to simplify that before it is too late. Thanks again.
Date: 2010-04-05 03:09 Sender: Francisco Figueiredo jr. Hi, Noah! Didn't try it yet. I'm going to try it soon and will let you know.
Date: 2010-04-03 16:13 Sender: Noah Misch Francisco, did you get a chance to try that instrumentation?
Date: 2010-03-22 01:38 Sender: Noah Misch Hi Francisco, Thank you for reviewing. I should have mentioned, the second test does pass already; I just added it for completeness. I'm not quite sure why we get different results on the first test, though. I am attaching an alternate patch, "debug-timeout.patch", that includes just the test cases and some extra noise to show the timeouts used for each query. Snip from the output in my setup: Start timeout test 1 listening for response with timeout 15 Sending query: SET CLIENT_ENCODING TO UTF8 ... listening for response with timeout 0 Sending query: set standard_conforming_strings=off ... listening for response with timeout 20 Sending query: show escape_string_warning ... listening for response with timeout 0 Sending query: SELECT ((E'foo')::text), pg_sleep(1.5) ... listening for response with timeout 0 Sending query: unlisten * ... listening for response with timeout 0 End timeout test 1 Here is the output after applying my proposed fix as well: Start timeout test 1 listening for response with timeout 15 Sending query: SET CLIENT_ENCODING TO UTF8 ... listening for response with timeout 0 Sending query: set standard_conforming_strings=off ... listening for response with timeout 20 Sending query: show escape_string_warning ... listening for response with timeout 0 Sending query: SELECT ((E'foo')::text), pg_sleep(1.5) ... listening for response with timeout 1 listening for response with timeout 1 Caught exception (hopefully a timeout): Npgsql.NpgsqlException: A timeout has occured. If you were establishing a connection, increase Timeout value in ConnectionString. If you were executing a command, increase the CommandTim\ eout value in ConnectionString or in your NpgsqlCommand object. at Npgsql.NpgsqlState.ProcessBackendResponsesEnum(NpgsqlConnector context) in c:\cygwin\home\noah.misch\src\npgsql\reprod\src\Npgsql\NpgsqlState.cs:line 383 at Npgsql.NpgsqlReadyState.QueryEnum(NpgsqlConnector context, NpgsqlCommand command) in c:\cygwin\home\noah.misch\src\npgsql\reprod\src\Npgsql\NpgsqlReadyState\ .cs:line 67 at Npgsql.NpgsqlConnector.QueryEnum(NpgsqlCommand queryCommand) in c:\cygwin\home\noah.misch\src\npgsql\reprod\src\Npgsql\NpgsqlConnector.cs:line 294 at Npgsql.NpgsqlCommand.GetReader(CommandBehavior cb) in c:\cygwin\home\noah.misch\src\npgsql\reprod\src\Npgsql\NpgsqlCommand.cs:line 590 at Npgsql.NpgsqlCommand.ExecuteNonQuery() in c:\cygwin\home\noah.misch\src\npgsql\reprod\src\Npgsql\NpgsqlCommand.cs:line 492 at NpgsqlTests.CommandTests.TimeoutFirstParameters() in c:\cygwin\home\noah.misch\src\npgsql\reprod\testsuite\noninteractive\NUnit20\CommandTests.cs:line 3552 Sending query: unlisten * ... listening for response with timeout 0 End timeout test 1 What output do you get?
Date: 2010-03-20 23:39 Sender: Francisco Figueiredo jr. Hi! I'm not being able to reproduce your problem. As you noticed, I removed the command timeout reset the internal Npgsql command was doing. I added your test cases and they all passed. I set standard_conforming_strings = off too.

Attached Files:

Attachments:

npgsql-timeout-param.patch

debug-timeout.patch

Changes:

Field	Old Value	Date	By
File Added	462: debug-timeout.patch	2010-03-22 01:39	nmisch
File Added	458: npgsql-timeout-param.patch	2010-03-16 07:02	nmisch