pg.ddx.io  pgsql-bugs@postgresql.org mailing list archive  
help / color / mirror / Atom feed
From: Alexander Lakhin <exclusion@gmail.com>
To: pgsql-bugs@lists.postgresql.org
Subject: Re: BUG #16154: pg_ctl restart with a logfile fails sometimes (on Windows)
Date: Fri, 6 Dec 2019 11:00:01 +0300
Message-ID: <e5179494-715e-f8a3-266b-0cf52adac8f4@gmail.com> (raw)
In-Reply-To: <16154-1ccf0b537b24d5e0@postgresql.org>
References: <16154-1ccf0b537b24d5e0@postgresql.org>

06.12.2019 10:00, PG Bug reporting form wrote:
> When performing regression tests on Windows intermittent failures are
> observed, e.g. in src/bin/pg_basebackup test:
> vcregress taptest src/bin/pg_basebackup
> ...
> t/010_pg_basebackup.pl ... 10/106 Bailout called.  Further testing stopped: 
> system pg_ctl failed
> FAILED--Further testing stopped: system pg_ctl failed
>
>
> 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
>
> The issue is caused by sporadic "pg_ctl ... restart -l logfile" failures.

To reproduce this issue reliably I propose the simple demo patch
(delay_after_unlink_pid p, li { white-space: pre-wrap;).
With the delay added the "pg_ctl ... restart -l logfile" command (and
"vcregress taptest src/bin/pg_basebackup") fails always.
Error message is not very informational, but debugging shows that the
file in question is the log file, specified when running the command:
"C:\Windows\system32\cmd.exe" /C
""C:/src/postgresql/tmp_install/bin/postgres.exe" -D
"C:/src/postgresql/src/bin/pg_basebackup/tmp_check/t_010_pg_basebackup_main_data/pgdata"
--cluster-name=main < "nul" >>
"/C:/src/postgresql/src/bin/pg_basebackup/tmp_check/log/010_pg_basebackup_main.log/"
2>&1"

If this file is still opened by the previous server shell (it can happen
when the previous server instance has unlinked it's pid file, but it's
CMD shell is still running), the next CMD start fails with the
aforementioned error message.

To fix this issue I propose the attached patch
(fix_logfile_sharing_violation ).
With the patch, pg_ctl will wait for the log file to become available
(for 30 seconds). And if the file still could not be opened (it can be
reproduced with a larger delay in the demo patch), you'll get more
meaningful message:
/pg_ctl: could not access log file
"C:/src/postgresql/src/bin/pg_basebackup/tmp_check/log/010_pg_basebackup_main.log":
Permission denied/

Best regards,
Alexander

Attachments:

  [text/x-patch] delay_after_unlink_pid.patch (392B, ../e5179494-715e-f8a3-266b-0cf52adac8f4@gmail.com/3-delay_after_unlink_pid.patch)
  download | inline diff:
diff --git a/src/backend/utils/init/miscinit.c b/src/backend/utils/init/miscinit.c
index 83c9514856..130d666f33 100644
--- a/src/backend/utils/init/miscinit.c
+++ b/src/backend/utils/init/miscinit.c
@@ -858,6 +858,7 @@ UnlinkLockFiles(int status, Datum arg)
 	 */
 	ereport(IsPostmasterEnvironment ? LOG : NOTICE,
 			(errmsg("database system is shut down")));
+	pg_usleep(1000000L);
 }
 
 /*

  [text/x-patch] fix_logfile_sharing_violation.patch (922B, ../e5179494-715e-f8a3-266b-0cf52adac8f4@gmail.com/4-fix_logfile_sharing_violation.patch)
  download | inline diff:
diff --git a/src/bin/pg_ctl/pg_ctl.c b/src/bin/pg_ctl/pg_ctl.c
index 65f9fb4c0a..9bc44b2de4 100644
--- a/src/bin/pg_ctl/pg_ctl.c
+++ b/src/bin/pg_ctl/pg_ctl.c
@@ -519,8 +519,21 @@ start_postmaster(void)
 		comspec = "CMD";
 
 	if (log_file != NULL)
+	{
+		/* Check the log file availability to prevent CMD.EXE failing with
+		 * ERROR_SHARING_VIOLATION, e.g. when the log file is still opened
+		 * by the previous server shell.
+		 */
+		FILE *fd = fopen(log_file, "w+");
+		if (!fd) {
+			write_stderr(_("%s: could not access log file \"%s\": %s\n"),
+						 progname, log_file, strerror(errno));
+			exit(1);
+		}
+		fclose(fd);
 		snprintf(cmd, MAXPGPATH, "\"%s\" /C \"\"%s\" %s%s < \"%s\" >> \"%s\" 2>&1\"",
 				 comspec, exec_path, pgdata_opt, post_opts, DEVNULL, log_file);
+	}
 	else
 		snprintf(cmd, MAXPGPATH, "\"%s\" /C \"\"%s\" %s%s < \"%s\" 2>&1\"",
 				 comspec, exec_path, pgdata_opt, post_opts, DEVNULL);

view thread (12+ messages)  latest in thread

Message-ID: <e5179494-715e-f8a3-266b-0cf52adac8f4@gmail.com>
Permalink:  ../e5179494-715e-f8a3-266b-0cf52adac8f4@gmail.com/
Also on:    postgresql.org/message-id/e5179494-715e-f8a3-266b-0cf52adac8f4@gmail.com

 ·  · 

reply

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-bugs@postgresql.org
  Cc: exclusion@gmail.com, pgsql-bugs@lists.postgresql.org
  Subject: Re: BUG #16154: pg_ctl restart with a logfile fails sometimes (on Windows)
  In-Reply-To: <e5179494-715e-f8a3-266b-0cf52adac8f4@gmail.com>

* 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