Thread: BUG #2569: statement_timeout bug on Windows

BUG #2569: statement_timeout bug on Windows

From
"James"
Date:
The following bug has been logged online:

Bug reference:      2569
Logged by:          James
Email address:      im-james@hotmail.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?

Re: BUG #2569: statement_timeout bug on Windows

From
Bruce Momjian
Date:
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@hotmail.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@momjian.us
  EnterpriseDB    http://www.enterprisedb.com

  + If your life is a hard drive, Christ can be your backup. +
Index: src/backend/port/win32/timer.c
===================================================================
RCS file: /cvsroot/pgsql/src/backend/port/win32/timer.c,v
retrieving revision 1.9
diff -c -c -r1.9 timer.c
*** src/backend/port/win32/timer.c    9 Aug 2006 17:33:52 -0000    1.9
--- src/backend/port/win32/timer.c    9 Aug 2006 17:34:11 -0000
***************
*** 56,62 ****
                  timerCommArea.value.it_value.tv_usec == 0)
                  waittime = INFINITE;    /* Cancel the interrupt */
              else
!                 waittime = timerCommArea.value.it_value.tv_usec / 10 + timerCommArea.value.it_value.tv_sec * 1000;
              ResetEvent(timerCommArea.event);
              LeaveCriticalSection(&timerCommArea.crit_sec);
          }
--- 56,63 ----
                  timerCommArea.value.it_value.tv_usec == 0)
                  waittime = INFINITE;    /* Cancel the interrupt */
              else
!                 /* WaitForSingleObjectEx() uses milliseconds */
!                 waittime = timerCommArea.value.it_value.tv_usec / 1000 + timerCommArea.value.it_value.tv_sec * 1000;
              ResetEvent(timerCommArea.event);
              LeaveCriticalSection(&timerCommArea.crit_sec);
          }

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

From
Tom Lane
Date:
Bruce Momjian <bruce@momjian.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

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

From
Bruce Momjian
Date:
Tom Lane wrote:
> Bruce Momjian <bruce@momjian.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@momjian.us
  EnterpriseDB    http://www.enterprisedb.com

  + If your life is a hard drive, Christ can be your backup. +
Index: src/backend/port/win32/timer.c
===================================================================
RCS file: /cvsroot/pgsql/src/backend/port/win32/timer.c,v
retrieving revision 1.10
diff -c -c -r1.10 timer.c
*** src/backend/port/win32/timer.c    9 Aug 2006 17:47:03 -0000    1.10
--- src/backend/port/win32/timer.c    9 Aug 2006 20:39:16 -0000
***************
*** 56,63 ****
--- 56,69 ----
                  timerCommArea.value.it_value.tv_usec == 0)
                  waittime = INFINITE;    /* Cancel the interrupt */
              else
+             {
+                 /* Minimum wait time is 1ms */
+                 if (timerCommArea.value.it_value.tv_sec == 0 &&
+                     timerCommArea.value.it_value.tv_usec < 1000)
+                     timerCommArea.value.it_value.tv_usec = 1000;
                  /* WaitForSingleObjectEx() uses milliseconds */
                  waittime = timerCommArea.value.it_value.tv_usec / 1000 + timerCommArea.value.it_value.tv_sec * 1000;
+             }
              ResetEvent(timerCommArea.event);
              LeaveCriticalSection(&timerCommArea.crit_sec);
          }

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

From
Tom Lane
Date:
Bruce Momjian <bruce@momjian.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

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

From
Bruce Momjian
Date:
OK, done.

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

Tom Lane wrote:
> Bruce Momjian <bruce@momjian.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@momjian.us
  EnterpriseDB    http://www.enterprisedb.com

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