From: r.zharkov@postgrespro.ru
To: Badrul Chowdhury <bachow@microsoft.com>
Cc: Tom Lane <tgl@sss.pgh.pa.us>
Cc: pgsql-hackers@lists.postgresql.org
Subject: Re: Intermittent pg_ctl failures on Windows
Date: Wed, 17 Jul 2019 17:40:36 +0700
Message-ID: <0057a0ce5a8893e4713a9a9d7e352162@postgrespro.ru> (raw)
In-Reply-To: <DM5PR2101MB0984D3DB39BCCCF189ECD15ED1D30@DM5PR2101MB0984.namprd21.prod.outlook.com>
References: <16922.1520722108@sss.pgh.pa.us>
<DM5PR2101MB0984D3DB39BCCCF189ECD15ED1D30@DM5PR2101MB0984.namprd21.prod.outlook.com>
Hello!
We reproduced these errors on out buildfarm and my windows workstation.
We used small TAP test that restarts PostgresNode in loop. Additionally,
constant WAITS_PER_SEC in the pg_ctl.c file has been increased 1000
times.
There are two different problems with pg_ctl:
1 - share access to postmaster.pid;
2 - share access to logfile. Postmaster runs in the shell (CMD.EXE).
When the server stops cmd.exe may blocks logfile from been opened by new
cmd.exe.
> waiting for server to shut down.... done
> server stopped
> waiting for server to start....The process cannot access the file
> because it is being used by another process.
> stopped waiting
> pg_ctl: could not start server
> Examine the log output.
To avoid the first error we made two changes:
pg_ctl now opens the postmaster.pid file using pgwin32_open() function
to correctly handle share locks.
On Windows systems we cannot handle ERROR_DELETE_PENDING because
GetLastError() returns ERROR_ACCESS_DENIED instead.
So we rename the lock files before delete them.
To avoid the second error we added the wait for cmd.exe finish in the
do_stop() and do_restart() functions.
Git patch is in the attachment.
On 2018-03-12 18:55, Badrul Chowdhury wrote:
> Hi Tom,
>
> This is a great catch. I am looking into it: I will start by
> reproducing the error as you suggested.
>
> Thanks,
> Badrul
>
> -----Original Message-----
> From: Tom Lane [mailto:tgl@sss.pgh.pa.us]
> Sent: Saturday, March 10, 2018 2:48 PM
> To: pgsql-hackers@lists.postgresql.org
> Subject: Intermittent pg_ctl failures on Windows
>
> The buildfarm's Windows members occasionally show weird pg_ctl
> failures, for instance this recent case:
>
> https://na01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fbuildfarm.postgresql.org%2Fcgi-bin%...
>
> ### Restarting node "master"
> # Running: pg_ctl -D
> G:/prog/bf/root/HEAD/pgsql.build/src/test/recovery/tmp_check/t_006_logical_decoding_master_data/pgdata
> -l
> G:/prog/bf/root/HEAD/pgsql.build/src/test/recovery/tmp_check/log/006_logical_decoding_master.log
> restart waiting for server to shut down.... done server stopped
> waiting for server to start....The process cannot access the file
> because it is being used by another process.
> stopped waiting
> pg_ctl: could not start server
> Examine the log output.
> Bail out! system pg_ctl failed
>
> or this one:
>
> https://na01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fbuildfarm.postgresql.org%2Fcgi-bin%...
>
> ### Stopping node "subscriber" using mode fast # Running: pg_ctl -D
> c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_subscriber_data/pgdata
> -m fast stop waiting for server to shut down....pg_ctl: could not open
> PID file
> "c:/prog/bf/root/HEAD/pgsql.build/src/test/subscription/tmp_check/t_001_rep_changes_subscriber_data/pgdata/postmaster.pid":
> Permission denied Bail out! system pg_ctl failed
>
> I'd been writing these off as Microsoft randomness and/or antivirus
> interference, but it suddenly occurred to me that there might be a
> consistent explanation: since commit f13ea95f9, when pg_ctl is waiting
> for server start/stop, it is trying to read postmaster.pid
> more-or-less concurrently with the postmaster writing to that file.
> On Unix that's not much of a problem, but I believe that on Windows
> you have to specifically open the file with sharing enabled, or you
> get error messages like these.
> The postmaster should be enabling sharing, because port.h redirects
> open/fopen to pgwin32_open/pgwin32_fopen which enable the sharing
> flags.
> But it only does that #ifndef FRONTEND. So pg_ctl is just using naked
> open(), which could explain these failures.
>
> If this theory is accurate, it should be pretty easy to replicate the
> problem if you modify the postmaster to hold postmaster.pid open
> longer when rewriting it, e.g. stick fractional-second sleeps into
> CreateLockFile and AddToDataDirLockFile.
>
> I'm not in a position to investigate this in detail nor test a fix,
> but I think somebody should.
>
> regards, tom lane
--
regars, Roman Zharkov
Attachments:
[text/x-diff] pg_ctl.patch (7.0K, ../0057a0ce5a8893e4713a9a9d7e352162@postgrespro.ru/2-pg_ctl.patch)
download | inline diff:
From 7db244f6224d772a0c0fb26e6dfc38b2bad7a93e Mon Sep 17 00:00:00 2001
From: Roman Zharkov <r.zharkov@postgrespro.ru>
Date: Fri, 12 Jul 2019 13:01:58 +0700
Subject: [PATCH] [refer #PGPRO-2846] Avoid share locks on log_file between old
and new cmd.exe when the server restarts. pg_ctl now opens the postmaster.pid
file using pgwin32_open() function to correctly handle share locks. On
Windows systems we cannot handle ERROR_DELETE_PENDING because GetLastError()
returns ERROR_ACCESS_DENIED instead. So we rename the lock files before
delete them. Discussion:
https://www.postgresql.org/message-id/flat/16922.1520722108%40sss.pgh.pa.us
---
src/backend/utils/init/miscinit.c | 18 ++++-
src/bin/pg_ctl/pg_ctl.c | 135 ++++++++++++++++++++++++++++++++++++++
2 files changed, 150 insertions(+), 3 deletions(-)
diff --git a/src/backend/utils/init/miscinit.c b/src/backend/utils/init/miscinit.cindex ce929d8806..32a3e9520f 100644--- a/src/backend/utils/init/miscinit.c+++ b/src/backend/utils/init/miscinit.c@@ -840,9 +840,21 @@ UnlinkLockFiles(int status, Datum arg)
foreach(l, lock_files)
{
- char *curfile = (char *) lfirst(l);-- unlink(curfile);+ /*+ * On Windows systems we cannot handle ERROR_DELETE_PENDING+ * because GetLastError() returns ERROR_ACCESS_DENIED instead.+ * So rename the file first.+ */+ char *tmpfile;+ char *curfile = (char *)lfirst(l);+ tmpfile = psprintf("%s.deleted", curfile);+ if (rename(curfile, tmpfile) == 0) {+ unlink(tmpfile);+ }+ else {+ unlink(curfile);+ }+ pfree(tmpfile);
/* Should we complain if the unlink fails? */
}
/* Since we're about to exit, no need to reclaim storage */
diff --git a/src/bin/pg_ctl/pg_ctl.c b/src/bin/pg_ctl/pg_ctl.cindex ed2396aa6c..6b6705e0f2 100644--- a/src/bin/pg_ctl/pg_ctl.c+++ b/src/bin/pg_ctl/pg_ctl.c@@ -31,6 +31,8 @@
#ifdef WIN32 /* on Unix, we don't need libpq */
#include "pqexpbuffer.h"
+#include "windows.h"+#include "tlhelp32.h"
#endif
/* PID can be negative for standalone backend */
@@ -75,6 +77,11 @@ typedef enum
static bool do_wait = true;
static int wait_seconds = DEFAULT_WAIT;
+#ifdef WIN32+static int windows_shell_wait_seconds = 1;+#define open(a,b,c) pgwin32_open(a,b,c) /* It is not necessary to include whole port.h */+#define fopen(a,b) pgwin32_fopen(a,b)+#endif
static bool wait_seconds_arg = false;
static bool silent_mode = false;
static ShutdownMode shutdown_mode = FAST_MODE;
@@ -110,6 +117,8 @@ static pid_t postmasterPID = -1;
#define shutdownEvent shutdownHandles[0]
#define postmasterProcess shutdownHandles[1]
+static pgpid_t pgwin32_getppid(pgpid_t pid);+static bool pgwin32_parent_shell_is_alive(pid_t pid);
#endif
@@ -867,6 +876,12 @@ do_stop(void)
pid = get_pgpid(false);
+#ifdef WIN32+ /* On Windows systems we must additionaly check status of the processes after server stops */+ pgpid_t postmasters_shell_pid;+ postmasters_shell_pid = pgwin32_getppid(pid);+#endif+
if (pid == 0) /* no pid file */
{
write_stderr(_("%s: PID file \"%s\" does not exist\n"), progname, pid_file);
@@ -934,6 +949,32 @@ do_stop(void)
"waiting for session-initiated disconnection.\n"));
exit(1);
}
++#ifdef WIN32+ /*+ * On Windows systems postmaster's shell may still run after postmaster.pid file has deleted.+ * This may lead to share locks on log_file between old and new cmd.exe when the server restarts.+ * The share locks do not allow the new cmd.exe to run.+ */+ if (postmasters_shell_pid > 0 && pgwin32_parent_shell_is_alive(postmasters_shell_pid))+ {+ print_msg(_("\npostmaster's shell is still alive. waiting for server to shut down again..."));+ /* wait for stop */+ for (cnt = 0; cnt < windows_shell_wait_seconds * WAITS_PER_SEC; cnt++)+ {+ if (pgwin32_parent_shell_is_alive(postmasters_shell_pid))+ {+ if (cnt % WAITS_PER_SEC == 0)+ print_msg(".");+ pg_usleep(USEC_PER_SEC / WAITS_PER_SEC);+ }+ else+ break;+ }+ /* Do not fail if the parent process is still running. */+ }+#endif+
print_msg(_(" done\n"));
print_msg(_("server stopped\n"));
@@ -954,6 +995,12 @@ do_restart(void)
pid = get_pgpid(false);
+#ifdef WIN32+ /* On Windows systems we must additionaly check status of the processes after server stops */+ pgpid_t postmasters_shell_pid;+ postmasters_shell_pid = pgwin32_getppid(pid);+#endif+
if (pid == 0) /* no pid file */
{
write_stderr(_("%s: PID file \"%s\" does not exist\n"),
@@ -1026,6 +1073,31 @@ do_restart(void)
exit(1);
}
+#ifdef WIN32+ /*+ * On Windows systems postmaster's shell may still run after postmaster.pid file has deleted.+ * This may lead to share locks on log_file between old and new cmd.exe when the server restarts.+ * The share locks do not allow the new cmd.exe to run.+ */+ if (postmasters_shell_pid > 0 && pgwin32_parent_shell_is_alive(postmasters_shell_pid))+ {+ print_msg(_("\npostmaster's shell is still alive. waiting for server to shut down again..."));+ /* wait for stop */+ for (cnt = 0; cnt < windows_shell_wait_seconds * WAITS_PER_SEC; cnt++)+ {+ if (pgwin32_parent_shell_is_alive(postmasters_shell_pid))+ {+ if (cnt % WAITS_PER_SEC == 0)+ print_msg(".");+ pg_usleep(USEC_PER_SEC / WAITS_PER_SEC);+ }+ else+ break;+ }+ /* Do not fail if the parent process is still running. */+ }+#endif+
print_msg(_(" done\n"));
print_msg(_("server stopped\n"));
}
@@ -1176,6 +1248,69 @@ do_promote(void)
* utility routines
*/
+#ifdef WIN32+static pgpid_t+pgwin32_getppid(pgpid_t pid)+{+ /* Finds parent process id. Returns 0 by default. */+ HANDLE hSnapshot;+ PROCESSENTRY32 pe32;+ pgpid_t ppid = 0;++ hSnapshot = CreateToolhelp32Snapshot(TH32CS_SNAPPROCESS, (DWORD)pid);+ __try{+ if (hSnapshot == INVALID_HANDLE_VALUE) __leave;++ ZeroMemory(&pe32, sizeof(pe32));+ pe32.dwSize = sizeof(pe32);+ if (!Process32First(hSnapshot, &pe32)) __leave;++ do{+ if (pe32.th32ProcessID == pid){+ ppid = (pgpid_t)pe32.th32ParentProcessID;+ break;+ }+ } while (Process32Next(hSnapshot, &pe32));++ }+ __finally{+ if (hSnapshot != INVALID_HANDLE_VALUE) CloseHandle(hSnapshot);+ }+ return ppid;+}++static bool+pgwin32_parent_shell_is_alive(pid_t pid)+{+ {+ /* Checks the parent cmd.exe with specified pid is running */+ HANDLE hSnapshot;+ PROCESSENTRY32 pe32;+ bool res = false;++ hSnapshot = CreateToolhelp32Snapshot(TH32CS_SNAPPROCESS, (DWORD)pid);+ __try{+ if (hSnapshot == INVALID_HANDLE_VALUE) __leave;++ ZeroMemory(&pe32, sizeof(pe32));+ pe32.dwSize = sizeof(pe32);+ if (!Process32First(hSnapshot, &pe32)) __leave;++ do{+ if (pe32.th32ProcessID == pid && strcmp(pe32.szExeFile, "cmd.exe") == 0){+ res = true;+ }+ } while (Process32Next(hSnapshot, &pe32));++ }+ __finally{+ if (hSnapshot != INVALID_HANDLE_VALUE) CloseHandle(hSnapshot);+ }+ return res;+ }+}+#endif+
static bool
postmaster_is_alive(pid_t pid)
{
--
2.14.1.windows.1
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-hackers@postgresql.org
Cc: r.zharkov@postgrespro.ru, bachow@microsoft.com, tgl@sss.pgh.pa.us, pgsql-hackers@lists.postgresql.org
Subject: Re: Intermittent pg_ctl failures on Windows
In-Reply-To: <0057a0ce5a8893e4713a9a9d7e352162@postgrespro.ru>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox