Re: BUG #11805: Missing SetServiceStatus call during service shutdown in pg_ctl (Windows only)

The following bug has been logged on the website:

Bug reference: 11805
Logged by: Krystian Bigaj
Email address: krystian(dot)bigaj(at)gmail(dot)com
PostgreSQL version: 9.3.5
Operating system: Windows 7 Pro x64
Description:

pg_ctl on Windows during service start/shutdown should notify service
manager about it's status by increment dwCheckPoint and call to
SetServiceStatus/pgwin32_SetServiceStatus.

However during shutdown there is a missing call to SetServiceStatus.
See src\bin\pg_ctl\pg_ctl.c:
[code]
static void WINAPI
pgwin32_ServiceMain(DWORD argc, LPTSTR *argv)
{
...
/*
* Increment the checkpoint and try again Abort after 12
* checkpoints as the postmaster has probably hung
*/
while (WaitForSingleObject(postmasterProcess, 5000) ==
WAIT_TIMEOUT && status.dwCheckPoint < 12)
status.dwCheckPoint++; <------- missing SetServiceStatus
call
break;

case (WAIT_OBJECT_0 + 1): /* postmaster went down */
break;
[/code]

As you can see there is only a dwCheckPoint increment, but there is no call
to SetServiceStatus(hStatus, (LPSERVICE_STATUS) &status);
This problem was reported before here:
http://www.postgresql.org/message-id/CAN=kAeGOEmfh_+vdg+2oD=9KhWzGn4NNqfZNdHoQ_2QOsHhuLQ@mail.gmail.com

Another problem is with above condition "status.dwCheckPoint < 12" if
service (pg_ctl) is started with -w parameter (wait for startup).
In that case test_postmaster_connection(true) increments
status.dwCheckPoint,
so during shutdown that value can be larger than 0 (and even larger than 12,
because default wait time is 60s), so there could be only one 5000ms wait
for postmaster shutdown.

Patch to fix for this bugs could looks like this:
[code]
case WAIT_OBJECT_0: /* shutdown event */
/*
* Value status.dwCheckPoint can be incremented by
test_postmaster_connection(true)
* so dwCheckPoint might not start from 0.
*/
int maxShutdownCheckPoint = status.dwCheckPoint + 12;

kill(postmasterPID, SIGINT);

/*
* Increment the checkpoint and try again Abort after 12
* checkpoints as the postmaster has probably hung
*/
while (WaitForSingleObject(postmasterProcess, 5000) ==
WAIT_TIMEOUT && status.dwCheckPoint < maxShutdownCheckPoint)
{
status.dwCheckPoint++;
SetServiceStatus(hStatus, (LPSERVICE_STATUS) &status);
}
break;
[/code]

Patch for 9.3 in attachment (previous inline patch didn't compile)

Best regards,
Krystian Bigaj

On 28 October 2014 08:02, <krystian(dot)bigaj(at)gmail(dot)com> wrote:

> The following bug has been logged on the website:
>
> Bug reference: 11805
> Logged by: Krystian Bigaj
> Email address: krystian(dot)bigaj(at)gmail(dot)com
> PostgreSQL version: 9.3.5
> Operating system: Windows 7 Pro x64
> Description:
>
> pg_ctl on Windows during service start/shutdown should notify service
> manager about it's status by increment dwCheckPoint and call to
> SetServiceStatus/pgwin32_SetServiceStatus.
>
> However during shutdown there is a missing call to SetServiceStatus.
> See src\bin\pg_ctl\pg_ctl.c:
> [code]
> static void WINAPI
> pgwin32_ServiceMain(DWORD argc, LPTSTR *argv)
> {
> ...
> /*
> * Increment the checkpoint and try again Abort after 12
> * checkpoints as the postmaster has probably hung
> */
> while (WaitForSingleObject(postmasterProcess, 5000) ==
> WAIT_TIMEOUT && status.dwCheckPoint < 12)
> status.dwCheckPoint++; <------- missing SetServiceStatus
> call
> break;
>
> case (WAIT_OBJECT_0 + 1): /* postmaster went down */
> break;
> [/code]
>
> As you can see there is only a dwCheckPoint increment, but there is no call
> to SetServiceStatus(hStatus, (LPSERVICE_STATUS) &status);
> This problem was reported before here:
>
> http://www.postgresql.org/message-id/CAN=kAeGOEmfh_+vdg+2oD=9KhWzGn4NNqfZNdHoQ_2QOsHhuLQ@mail.gmail.com
>
> Another problem is with above condition "status.dwCheckPoint < 12" if
> service (pg_ctl) is started with -w parameter (wait for startup).
> In that case test_postmaster_connection(true) increments
> status.dwCheckPoint,
> so during shutdown that value can be larger than 0 (and even larger than
> 12,
> because default wait time is 60s), so there could be only one 5000ms wait
> for postmaster shutdown.
>
> Patch to fix for this bugs could looks like this:
> [code]
> case WAIT_OBJECT_0: /* shutdown event */
> /*
> * Value status.dwCheckPoint can be incremented by
> test_postmaster_connection(true)
> * so dwCheckPoint might not start from 0.
> */
> int maxShutdownCheckPoint = status.dwCheckPoint + 12;
>
> kill(postmasterPID, SIGINT);
>
> /*
> * Increment the checkpoint and try again Abort after 12
> * checkpoints as the postmaster has probably hung
> */
> while (WaitForSingleObject(postmasterProcess, 5000) ==
> WAIT_TIMEOUT && status.dwCheckPoint < maxShutdownCheckPoint)
> {
> status.dwCheckPoint++;
> SetServiceStatus(hStatus, (LPSERVICE_STATUS) &status);
> }
> break;
> [/code]
>
>
>
> --
> Sent via pgsql-bugs mailing list (pgsql-bugs(at)postgresql(dot)org)
> To make changes to your subscription:
> http://www.postgresql.org/mailpref/pgsql-bugs
>

On Tue, Oct 28, 2014 at 07:02:41AM +0000, krystian(dot)bigaj(at)gmail(dot)com wrote:
> The following bug has been logged on the website:
>
> Bug reference: 11805
> Logged by: Krystian Bigaj
> Email address: krystian(dot)bigaj(at)gmail(dot)com
> PostgreSQL version: 9.3.5
> Operating system: Windows 7 Pro x64
> Description:
>
> pg_ctl on Windows during service start/shutdown should notify service
> manager about it's status by increment dwCheckPoint and call to
> SetServiceStatus/pgwin32_SetServiceStatus.
>
> However during shutdown there is a missing call to SetServiceStatus.
> See src\bin\pg_ctl\pg_ctl.c:

[ thread moved to hackers ]

Can a Windows person look into this issue?

http://www.postgresql.org/message-id/20141028070241.2593.58180@wrigleys.postgresql.org

The thread includes a patch. I need a second person to verify its
validity. Thanks.

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

+ Everyone has their own god. +

On Fri, Mar 20, 2015 at 9:48 PM, Bruce Momjian <bruce(at)momjian(dot)us> wrote:
> On Tue, Oct 28, 2014 at 07:02:41AM +0000, krystian(dot)bigaj(at)gmail(dot)com wrote:
>> The following bug has been logged on the website:
>>
>> Bug reference: 11805
>> Logged by: Krystian Bigaj
>> Email address: krystian(dot)bigaj(at)gmail(dot)com
>> PostgreSQL version: 9.3.5
>> Operating system: Windows 7 Pro x64
>> Description:
>>
>> pg_ctl on Windows during service start/shutdown should notify service
>> manager about it's status by increment dwCheckPoint and call to
>> SetServiceStatus/pgwin32_SetServiceStatus.
>>
>> However during shutdown there is a missing call to SetServiceStatus.
>> See src\bin\pg_ctl\pg_ctl.c:
>
> [ thread moved to hackers ]
>
> Can a Windows person look into this issue?
>
> http://www.postgresql.org/message-id/20141028070241.2593.58180@wrigleys.postgresql.org
>
> The thread includes a patch. I need a second person to verify its
> validity. Thanks.

FWIW, it looks sane to me to do so, ServiceMain declaration is in
charge to start the service, and to wait for the postmaster to stop,
and indeed process may increment dwcheckpoint in -w mode, and it
expects for process to wait for 12 times but this promise is broken.
The extra calls to SetServiceStatus are also welcome to let the SCM
know the current status in more details.

A back-patch would be good as well...
Regards,
--
Michael

On Sat, Mar 21, 2015 at 9:00 AM, Michael Paquier
<michael(dot)paquier(at)gmail(dot)com> wrote:
> On Fri, Mar 20, 2015 at 9:48 PM, Bruce Momjian <bruce(at)momjian(dot)us> wrote:
>> On Tue, Oct 28, 2014 at 07:02:41AM +0000, krystian(dot)bigaj(at)gmail(dot)com wrote:
>>> The following bug has been logged on the website:
>>>
>>> Bug reference: 11805
>>> Logged by: Krystian Bigaj
>>> Email address: krystian(dot)bigaj(at)gmail(dot)com
>>> PostgreSQL version: 9.3.5
>>> Operating system: Windows 7 Pro x64
>>> Description:
>>>
>>> pg_ctl on Windows during service start/shutdown should notify service
>>> manager about it's status by increment dwCheckPoint and call to
>>> SetServiceStatus/pgwin32_SetServiceStatus.
>>>
>>> However during shutdown there is a missing call to SetServiceStatus.
>>> See src\bin\pg_ctl\pg_ctl.c:
>>
>> [ thread moved to hackers ]
>>
>> Can a Windows person look into this issue?
>>
>> http://www.postgresql.org/message-id/20141028070241.2593.58180@wrigleys.postgresql.org
>>
>> The thread includes a patch. I need a second person to verify its
>> validity. Thanks.
>
> FWIW, it looks sane to me to do so, ServiceMain declaration is in
> charge to start the service, and to wait for the postmaster to stop,
> and indeed process may increment dwcheckpoint in -w mode, and it
> expects for process to wait for 12 times but this promise is broken.
> The extra calls to SetServiceStatus are also welcome to let the SCM
> know the current status in more details.

So, what's next here?

--
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

On Thu, Apr 30, 2015 at 9:53 PM, Robert Haas <robertmhaas(at)gmail(dot)com> wrote:
> On Sat, Mar 21, 2015 at 9:00 AM, Michael Paquier
> <michael(dot)paquier(at)gmail(dot)com> wrote:
>> On Fri, Mar 20, 2015 at 9:48 PM, Bruce Momjian <bruce(at)momjian(dot)us> wrote:
>>> On Tue, Oct 28, 2014 at 07:02:41AM +0000, krystian(dot)bigaj(at)gmail(dot)com wrote:
>>>> The following bug has been logged on the website:
>>>>
>>>> Bug reference: 11805
>>>> Logged by: Krystian Bigaj
>>>> Email address: krystian(dot)bigaj(at)gmail(dot)com
>>>> PostgreSQL version: 9.3.5
>>>> Operating system: Windows 7 Pro x64
>>>> Description:
>>>>
>>>> pg_ctl on Windows during service start/shutdown should notify service
>>>> manager about it's status by increment dwCheckPoint and call to
>>>> SetServiceStatus/pgwin32_SetServiceStatus.
>>>>
>>>> However during shutdown there is a missing call to SetServiceStatus.
>>>> See src\bin\pg_ctl\pg_ctl.c:
>>>
>>> [ thread moved to hackers ]
>>>
>>> Can a Windows person look into this issue?
>>>
>>> http://www.postgresql.org/message-id/20141028070241.2593.58180@wrigleys.postgresql.org
>>>
>>> The thread includes a patch. I need a second person to verify its
>>> validity. Thanks.
>>
>> FWIW, it looks sane to me to do so, ServiceMain declaration is in
>> charge to start the service, and to wait for the postmaster to stop,
>> and indeed process may increment dwcheckpoint in -w mode, and it
>> expects for process to wait for 12 times but this promise is broken.
>> The extra calls to SetServiceStatus are also welcome to let the SCM
>> know the current status in more details.
>
> So, what's next here?

I guess that a committer opinion would be welcome. IMO the current
behavior is a bug.
--
Michael

On Thu, Apr 30, 2015 at 3:08 PM, Michael Paquier <michael(dot)paquier(at)gmail(dot)com>
wrote:

> On Thu, Apr 30, 2015 at 9:53 PM, Robert Haas <robertmhaas(at)gmail(dot)com>
> wrote:
> > On Sat, Mar 21, 2015 at 9:00 AM, Michael Paquier
> > <michael(dot)paquier(at)gmail(dot)com> wrote:
> >> On Fri, Mar 20, 2015 at 9:48 PM, Bruce Momjian <bruce(at)momjian(dot)us>
> wrote:
> >>> On Tue, Oct 28, 2014 at 07:02:41AM +0000, krystian(dot)bigaj(at)gmail(dot)com
> wrote:
> >>>> The following bug has been logged on the website:
> >>>>
> >>>> Bug reference: 11805
> >>>> Logged by: Krystian Bigaj
> >>>> Email address: krystian(dot)bigaj(at)gmail(dot)com
> >>>> PostgreSQL version: 9.3.5
> >>>> Operating system: Windows 7 Pro x64
> >>>> Description:
> >>>>
> >>>> pg_ctl on Windows during service start/shutdown should notify service
> >>>> manager about it's status by increment dwCheckPoint and call to
> >>>> SetServiceStatus/pgwin32_SetServiceStatus.
> >>>>
> >>>> However during shutdown there is a missing call to SetServiceStatus.
> >>>> See src\bin\pg_ctl\pg_ctl.c:
> >>>
> >>> [ thread moved to hackers ]
> >>>
> >>> Can a Windows person look into this issue?
> >>>
> >>>
> http://www.postgresql.org/message-id/20141028070241.2593.58180@wrigleys.postgresql.org
> >>>
> >>> The thread includes a patch. I need a second person to verify its
> >>> validity. Thanks.
> >>
> >> FWIW, it looks sane to me to do so, ServiceMain declaration is in
> >> charge to start the service, and to wait for the postmaster to stop,
> >> and indeed process may increment dwcheckpoint in -w mode, and it
> >> expects for process to wait for 12 times but this promise is broken.
> >> The extra calls to SetServiceStatus are also welcome to let the SCM
> >> know the current status in more details.
> >
> > So, what's next here?
>
> I guess that a committer opinion would be welcome. IMO the current
> behavior is a bug.
>

Agreed, it pretty clearly is.

I've applied this patch (with a minor stylistic change), and backpatched.

--
Magnus Hagander
Me: http://www.hagander.net/
Work: http://www.redpill-linpro.com/