Re: [PATCHES] BUG #2569: statement_timeout bug on Windows

The following bug has been logged online:

Bug reference: 2569
Logged by: James
Email address: im-james(at)hotmail(dot)com
PostgreSQL version: 8.1.4
Operating system: Windows 200 Pro SP4
Description: statement_timeout bug on Windows
Details:

I'm using the latest version of postgresql (8.1.4) for Windows and I have a
problem with 'statement_timeout'.

Normally statement_timeout should "Abort any statement that takes over the
specified number of milliseconds". However on my pc, instead of milliseconds
it is tenth of seconds. For example: statement_timeout=30 actually means
'wait 3 seconds and abort' instead of wait 30 milliseconds.

I've tested this on the same version of postgresql on Linux and it works
correctly, as stated on the docs.

What do I do to find get this strange result? I do this.

set statement_timeout=30
show statement_timeout
VACUUM ANALYSE

The last statement is aborted after 3 seconds.

set statement_timeout=6
show statement_timeout
VACUUM ANALYSE

The last statement is aborted after 600 milliseconds.

Is this a bug (as I think) or could it be a misconfiguration of my OS, or of
postgresql?

I have a big "Oops" for this item. Seems in 8.0, we used the Win32 call
SetWaitableTimer(), which takes its timeout in 100 nanosecond intervals.
This was changed to use WaitForSingleObjectEx() in 8.1, but not
properly. The 8.0 code works fine.

The attached patch will fix the problem, and will be in 8.1.X. Sorry.

This affects all Win32 setitimer() calls in the backend, but the bug is
only related to micro-seconds, not full seconds. Because deadlock timer
is 1000ms, I don't think that is effected, but the stat file writer
timeout is 500ms, so that could be doing a 50sec timeout instead without
this patch.

---------------------------------------------------------------------------

James wrote:
>
> The following bug has been logged online:
>
> Bug reference: 2569
> Logged by: James
> Email address: im-james(at)hotmail(dot)com
> PostgreSQL version: 8.1.4
> Operating system: Windows 200 Pro SP4
> Description: statement_timeout bug on Windows
> Details:
>
> I'm using the latest version of postgresql (8.1.4) for Windows and I have a
> problem with 'statement_timeout'.
>
> Normally statement_timeout should "Abort any statement that takes over the
> specified number of milliseconds". However on my pc, instead of milliseconds
> it is tenth of seconds. For example: statement_timeout=30 actually means
> 'wait 3 seconds and abort' instead of wait 30 milliseconds.
>
> I've tested this on the same version of postgresql on Linux and it works
> correctly, as stated on the docs.
>
> What do I do to find get this strange result? I do this.
>
> set statement_timeout=30
> show statement_timeout
> VACUUM ANALYSE
>
> The last statement is aborted after 3 seconds.
>
>
> set statement_timeout=6
> show statement_timeout
> VACUUM ANALYSE
>
> The last statement is aborted after 600 milliseconds.
>
>
>
> Is this a bug (as I think) or could it be a misconfiguration of my OS, or of
> postgresql?
>
> ---------------------------(end of broadcast)---------------------------
> TIP 3: Have you checked our extensive FAQ?
>
> http://www.postgresql.org/docs/faq

--
Bruce Momjian bruce(at)momjian(dot)us
EnterpriseDB http://www.enterprisedb.com

+ If your life is a hard drive, Christ can be your backup. +

Bruce Momjian <bruce(at)momjian(dot)us> writes:
! /* WaitForSingleObjectEx() uses milliseconds */
> ! waittime = timerCommArea.value.it_value.tv_usec / 1000 + timerCommArea.value.it_value.tv_sec * 1000;

Seems like this probably ought to round up not down:

waittime = (timerCommArea.value.it_value.tv_usec + 999) / 1000 + timerCommArea.value.it_value.tv_sec * 1000;

Otherwise, an attempt to wait for 100 usec would convert to waittime 0,
which seems like a bad thing. In general the semantics of timed waits
are always supposed to be "you wait at least this long".

regards, tom lane

Tom Lane wrote:
> Bruce Momjian <bruce(at)momjian(dot)us> writes:
> ! /* WaitForSingleObjectEx() uses milliseconds */
> > ! waittime = timerCommArea.value.it_value.tv_usec / 1000 + timerCommArea.value.it_value.tv_sec * 1000;
>
> Seems like this probably ought to round up not down:
>
> waittime = (timerCommArea.value.it_value.tv_usec + 999) / 1000 + timerCommArea.value.it_value.tv_sec * 1000;
>
> Otherwise, an attempt to wait for 100 usec would convert to waittime 0,
> which seems like a bad thing. In general the semantics of timed waits
> are always supposed to be "you wait at least this long".

I thought about that, but because statement_timeout is in millis, and
not micros, we can't have a value that gets rounded down. I am
thinking a cleaner solution is to check for secs and if that is 0 and
microsecs < 1000, you set millis = 1.

Patch attached and applied to head and 8.1.X.

--
Bruce Momjian bruce(at)momjian(dot)us
EnterpriseDB http://www.enterprisedb.com

+ If your life is a hard drive, Christ can be your backup. +

Bruce Momjian <bruce(at)momjian(dot)us> writes:
> Tom Lane wrote:
>> Seems like this probably ought to round up not down:

> I thought about that, but because statement_timeout is in millis, and
> not micros, we can't have a value that gets rounded down. I am
> thinking a cleaner solution is to check for secs and if that is 0 and
> microsecs < 1000, you set millis = 1.

This is much uglier, probably slower, and fixes the problem only for
the zero case --- it is just as wrong to wait 1 msec when the caller
asked for 1.5 msec. And per your own observation, statement_timeout
is not the only source of the wait values, so this code must not
assume that the value is a multiple of 1msec.

Please do it the other way.

regards, tom lane

OK, done.

---------------------------------------------------------------------------

Tom Lane wrote:
> Bruce Momjian <bruce(at)momjian(dot)us> writes:
> > Tom Lane wrote:
> >> Seems like this probably ought to round up not down:
>
> > I thought about that, but because statement_timeout is in millis, and
> > not micros, we can't have a value that gets rounded down. I am
> > thinking a cleaner solution is to check for secs and if that is 0 and
> > microsecs < 1000, you set millis = 1.
>
> This is much uglier, probably slower, and fixes the problem only for
> the zero case --- it is just as wrong to wait 1 msec when the caller
> asked for 1.5 msec. And per your own observation, statement_timeout
> is not the only source of the wait values, so this code must not
> assume that the value is a multiple of 1msec.
>
> Please do it the other way.
>
> regards, tom lane
>
> ---------------------------(end of broadcast)---------------------------
> TIP 5: don't forget to increase your free space map settings

--
Bruce Momjian bruce(at)momjian(dot)us
EnterpriseDB http://www.enterprisedb.com

+ If your life is a hard drive, Christ can be your backup. +