More consistency for some file-related error message

Started by Michael Paquierover 7 years ago9 messages
#1Michael Paquier
michael@paquier.xyz
1 attachment(s)

Hi all,

While looking at the source code for more consistency work with error
messages, I have bumped into a couple of messages which could be
simplified, as those include in the name of the file manipulated
basically the same information as the context added.

I have finished with the attached. Note that for most of the messages,
I think that the context can be useful, like for example the stats
temporary file which could be user-defined, so those are left out.
There are also other cases, say the reorder buffer spill file, where we
may not know the path worked on, so the messages are kept consistent as
per HEAD.

That's a bit less work to do for translators, particularly with
pg_stat_statements.

Thoughts?
--
Michael

Attachments:

error-consistency.patchtext/x-diff; charset=us-asciiDownload
diff --git a/contrib/pg_stat_statements/pg_stat_statements.c b/contrib/pg_stat_statements/pg_stat_statements.c
index cc9efab243..33f9a79f54 100644
--- a/contrib/pg_stat_statements/pg_stat_statements.c
+++ b/contrib/pg_stat_statements/pg_stat_statements.c
@@ -642,19 +642,19 @@ pgss_shmem_startup(void)
 read_error:
 	ereport(LOG,
 			(errcode_for_file_access(),
-			 errmsg("could not read pg_stat_statement file \"%s\": %m",
+			 errmsg("could not read file \"%s\": %m",
 					PGSS_DUMP_FILE)));
 	goto fail;
 data_error:
 	ereport(LOG,
 			(errcode(ERRCODE_INVALID_PARAMETER_VALUE),
-			 errmsg("ignoring invalid data in pg_stat_statement file \"%s\"",
+			 errmsg("ignoring invalid data in file \"%s\"",
 					PGSS_DUMP_FILE)));
 	goto fail;
 write_error:
 	ereport(LOG,
 			(errcode_for_file_access(),
-			 errmsg("could not write pg_stat_statement file \"%s\": %m",
+			 errmsg("could not write file \"%s\": %m",
 					PGSS_TEXT_FILE)));
 fail:
 	if (buffer)
@@ -761,7 +761,7 @@ pgss_shmem_shutdown(int code, Datum arg)
 error:
 	ereport(LOG,
 			(errcode_for_file_access(),
-			 errmsg("could not write pg_stat_statement file \"%s\": %m",
+			 errmsg("could not write file \"%s\": %m",
 					PGSS_DUMP_FILE ".tmp")));
 	if (qbuffer)
 		free(qbuffer);
@@ -1871,7 +1871,7 @@ qtext_store(const char *query, int query_len,
 error:
 	ereport(LOG,
 			(errcode_for_file_access(),
-			 errmsg("could not write pg_stat_statement file \"%s\": %m",
+			 errmsg("could not write file \"%s\": %m",
 					PGSS_TEXT_FILE)));
 
 	if (fd >= 0)
@@ -1913,7 +1913,7 @@ qtext_load_file(Size *buffer_size)
 		if (errno != ENOENT)
 			ereport(LOG,
 					(errcode_for_file_access(),
-					 errmsg("could not read pg_stat_statement file \"%s\": %m",
+					 errmsg("could not read file \"%s\": %m",
 							PGSS_TEXT_FILE)));
 		return NULL;
 	}
@@ -1923,7 +1923,7 @@ qtext_load_file(Size *buffer_size)
 	{
 		ereport(LOG,
 				(errcode_for_file_access(),
-				 errmsg("could not stat pg_stat_statement file \"%s\": %m",
+				 errmsg("could not stat file \"%s\": %m",
 						PGSS_TEXT_FILE)));
 		CloseTransientFile(fd);
 		return NULL;
@@ -1939,7 +1939,7 @@ qtext_load_file(Size *buffer_size)
 		ereport(LOG,
 				(errcode(ERRCODE_OUT_OF_MEMORY),
 				 errmsg("out of memory"),
-				 errdetail("Could not allocate enough memory to read pg_stat_statement file \"%s\".",
+				 errdetail("Could not allocate enough memory to read file \"%s\".",
 						   PGSS_TEXT_FILE)));
 		CloseTransientFile(fd);
 		return NULL;
@@ -1958,7 +1958,7 @@ qtext_load_file(Size *buffer_size)
 		if (errno)
 			ereport(LOG,
 					(errcode_for_file_access(),
-					 errmsg("could not read pg_stat_statement file \"%s\": %m",
+					 errmsg("could not read file \"%s\": %m",
 							PGSS_TEXT_FILE)));
 		free(buf);
 		CloseTransientFile(fd);
@@ -2088,7 +2088,7 @@ gc_qtexts(void)
 	{
 		ereport(LOG,
 				(errcode_for_file_access(),
-				 errmsg("could not write pg_stat_statement file \"%s\": %m",
+				 errmsg("could not write file \"%s\": %m",
 						PGSS_TEXT_FILE)));
 		goto gc_fail;
 	}
@@ -2118,7 +2118,7 @@ gc_qtexts(void)
 		{
 			ereport(LOG,
 					(errcode_for_file_access(),
-					 errmsg("could not write pg_stat_statement file \"%s\": %m",
+					 errmsg("could not write file \"%s\": %m",
 							PGSS_TEXT_FILE)));
 			hash_seq_term(&hash_seq);
 			goto gc_fail;
@@ -2136,14 +2136,14 @@ gc_qtexts(void)
 	if (ftruncate(fileno(qfile), extent) != 0)
 		ereport(LOG,
 				(errcode_for_file_access(),
-				 errmsg("could not truncate pg_stat_statement file \"%s\": %m",
+				 errmsg("could not truncate file \"%s\": %m",
 						PGSS_TEXT_FILE)));
 
 	if (FreeFile(qfile))
 	{
 		ereport(LOG,
 				(errcode_for_file_access(),
-				 errmsg("could not write pg_stat_statement file \"%s\": %m",
+				 errmsg("could not write file \"%s\": %m",
 						PGSS_TEXT_FILE)));
 		qfile = NULL;
 		goto gc_fail;
@@ -2203,7 +2203,7 @@ gc_fail:
 	if (qfile == NULL)
 		ereport(LOG,
 				(errcode_for_file_access(),
-				 errmsg("could not write new pg_stat_statement file \"%s\": %m",
+				 errmsg("could not recreate file \"%s\": %m",
 						PGSS_TEXT_FILE)));
 	else
 		FreeFile(qfile);
@@ -2255,7 +2255,7 @@ entry_reset(void)
 	{
 		ereport(LOG,
 				(errcode_for_file_access(),
-				 errmsg("could not create pg_stat_statement file \"%s\": %m",
+				 errmsg("could not create file \"%s\": %m",
 						PGSS_TEXT_FILE)));
 		goto done;
 	}
@@ -2264,7 +2264,7 @@ entry_reset(void)
 	if (ftruncate(fileno(qfile), 0) != 0)
 		ereport(LOG,
 				(errcode_for_file_access(),
-				 errmsg("could not truncate pg_stat_statement file \"%s\": %m",
+				 errmsg("could not truncate file \"%s\": %m",
 						PGSS_TEXT_FILE)));
 
 	FreeFile(qfile);
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index bebe6405de..237a444bcd 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -3569,7 +3569,7 @@ XLogFileOpen(XLogSegNo segno)
 	if (fd < 0)
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not open write-ahead log file \"%s\": %m", path)));
+				 errmsg("could not open file \"%s\": %m", path)));
 
 	return fd;
 }
@@ -3758,7 +3758,7 @@ XLogFileClose(void)
 	if (close(openLogFile))
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not close log file %s: %m",
+				 errmsg("could not close file \"%s\": %m",
 						XLogFileNameP(ThisTimeLineID, openLogSegNo))));
 	openLogFile = -1;
 }
@@ -4092,7 +4092,7 @@ RemoveXlogFile(const char *segname, XLogRecPtr PriorRedoPtr, XLogRecPtr endptr)
 		{
 			ereport(LOG,
 					(errcode_for_file_access(),
-					 errmsg("could not rename old write-ahead log file \"%s\": %m",
+					 errmsg("could not rename file \"%s\": %m",
 							path)));
 			return;
 		}
@@ -4502,7 +4502,7 @@ WriteControlFile(void)
 	if (fd < 0)
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not create control file \"%s\": %m",
+				 errmsg("could not create file \"%s\": %m",
 						XLOG_CONTROL_FILE)));
 
 	errno = 0;
@@ -4514,7 +4514,8 @@ WriteControlFile(void)
 			errno = ENOSPC;
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not write to control file: %m")));
+				 errmsg("could not write to file \"%s\": %m",
+						XLOG_CONTROL_FILE)));
 	}
 	pgstat_report_wait_end();
 
@@ -4522,13 +4523,15 @@ WriteControlFile(void)
 	if (pg_fsync(fd) != 0)
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not fsync control file: %m")));
+				 errmsg("could not fsync file \"%s\": %m",
+						XLOG_CONTROL_FILE)));
 	pgstat_report_wait_end();
 
 	if (close(fd))
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not close control file: %m")));
+				 errmsg("could not close file \"%s\": %m",
+						XLOG_CONTROL_FILE)));
 }
 
 static void
@@ -4758,8 +4761,7 @@ UpdateControlFile(void)
 	if (fd < 0)
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not open control file \"%s\": %m",
-						XLOG_CONTROL_FILE)));
+				 errmsg("could not open file \"%s\": %m", XLOG_CONTROL_FILE)));
 
 	errno = 0;
 	pgstat_report_wait_start(WAIT_EVENT_CONTROL_FILE_WRITE_UPDATE);
@@ -4770,7 +4772,8 @@ UpdateControlFile(void)
 			errno = ENOSPC;
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not write to control file: %m")));
+				 errmsg("could not write to file \"%s\": %m",
+						XLOG_CONTROL_FILE)));
 	}
 	pgstat_report_wait_end();
 
@@ -4778,13 +4781,15 @@ UpdateControlFile(void)
 	if (pg_fsync(fd) != 0)
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not fsync control file: %m")));
+				 errmsg("could not fsync file \"%s\": %m",
+						XLOG_CONTROL_FILE)));
 	pgstat_report_wait_end();
 
 	if (close(fd))
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not close control file: %m")));
+				 errmsg("could not close file \"%s\": %m",
+						XLOG_CONTROL_FILE)));
 }
 
 /*
@@ -5684,7 +5689,7 @@ exitArchiveRecovery(TimeLineID endTLI, XLogRecPtr endOfLog)
 		if (close(fd))
 			ereport(ERROR,
 					(errcode_for_file_access(),
-					 errmsg("could not close log file %s: %m",
+					 errmsg("could not close file \"%s\": %m",
 							XLogFileNameP(ThisTimeLineID, startLogSegNo))));
 	}
 
@@ -10232,7 +10237,7 @@ assign_xlog_sync_method(int new_sync_method, void *extra)
 			if (pg_fsync(openLogFile) != 0)
 				ereport(PANIC,
 						(errcode_for_file_access(),
-						 errmsg("could not fsync log segment %s: %m",
+						 errmsg("could not fsync file \"%s\": %m",
 								XLogFileNameP(ThisTimeLineID, openLogSegNo))));
 			pgstat_report_wait_end();
 			if (get_sync_bit(sync_method) != get_sync_bit(new_sync_method))
@@ -10258,7 +10263,7 @@ issue_xlog_fsync(int fd, XLogSegNo segno)
 			if (pg_fsync_no_writethrough(fd) != 0)
 				ereport(PANIC,
 						(errcode_for_file_access(),
-						 errmsg("could not fsync log file %s: %m",
+						 errmsg("could not fsync file \"%s\": %m",
 								XLogFileNameP(ThisTimeLineID, segno))));
 			break;
 #ifdef HAVE_FSYNC_WRITETHROUGH
@@ -10266,7 +10271,7 @@ issue_xlog_fsync(int fd, XLogSegNo segno)
 			if (pg_fsync_writethrough(fd) != 0)
 				ereport(PANIC,
 						(errcode_for_file_access(),
-						 errmsg("could not fsync write-through log file %s: %m",
+						 errmsg("could not fsync write-through file \"%s\": %m",
 								XLogFileNameP(ThisTimeLineID, segno))));
 			break;
 #endif
@@ -10275,7 +10280,7 @@ issue_xlog_fsync(int fd, XLogSegNo segno)
 			if (pg_fdatasync(fd) != 0)
 				ereport(PANIC,
 						(errcode_for_file_access(),
-						 errmsg("could not fdatasync log file %s: %m",
+						 errmsg("could not fdatasync file \"%s\": %m",
 								XLogFileNameP(ThisTimeLineID, segno))));
 			break;
 #endif
diff --git a/src/bin/pg_basebackup/pg_recvlogical.c b/src/bin/pg_basebackup/pg_recvlogical.c
index ef85c9af4c..a242e0be88 100644
--- a/src/bin/pg_basebackup/pg_recvlogical.c
+++ b/src/bin/pg_basebackup/pg_recvlogical.c
@@ -197,7 +197,7 @@ OutputFsync(TimestampTz now)
 	if (fsync(outfd) != 0)
 	{
 		fprintf(stderr,
-				_("%s: could not fsync log file \"%s\": %s\n"),
+				_("%s: could not fsync file \"%s\": %s\n"),
 				progname, outfile, strerror(errno));
 		return false;
 	}
#2Tom Lane
tgl@sss.pgh.pa.us
In reply to: Michael Paquier (#1)
Re: More consistency for some file-related error message

Michael Paquier <michael@paquier.xyz> writes:

While looking at the source code for more consistency work with error
messages, I have bumped into a couple of messages which could be
simplified, as those include in the name of the file manipulated
basically the same information as the context added.

I have finished with the attached. Note that for most of the messages,
I think that the context can be useful, like for example the stats
temporary file which could be user-defined, so those are left out.
There are also other cases, say the reorder buffer spill file, where we
may not know the path worked on, so the messages are kept consistent as
per HEAD.

That's a bit less work to do for translators, particularly with
pg_stat_statements.

+1. Another thing I noticed is that we now have a fair amount of code
like this example in xlog.c:

errno = 0;
pgstat_report_wait_start(WAIT_EVENT_WAL_COPY_READ);
r = read(srcfd, buffer, nread);
if (r != nread)
{
if (r < 0)
ereport(ERROR,
(errcode_for_file_access(),
errmsg("could not read file \"%s\": %m",
path)));
else
ereport(ERROR,
(errmsg("could not read file \"%s\": read %d of %zu",
path, r, (Size) nread)));
}
pgstat_report_wait_end();
}

The short-read ereport has no errcode() call, meaning it will report
XX000, which seems like it's against project policy for foreseeable
errors. In this example ERRCODE_DATA_CORRUPTED seems better.

BTW, isn't the initial "errno = 0" dead code now?

regards, tom lane

#3Michael Paquier
michael@paquier.xyz
In reply to: Tom Lane (#2)
2 attachment(s)
Re: More consistency for some file-related error message

On Wed, Jul 18, 2018 at 10:57:16AM -0400, Tom Lane wrote:

+1.

Okay, thanks. I can always get that pushed first if there are no
objections. More can be always done, but that's already a nice cut.

The short-read ereport has no errcode() call, meaning it will report
XX000, which seems like it's against project policy for foreseeable
errors. In this example ERRCODE_DATA_CORRUPTED seems better.

Okay, my mistake then. All the error code paths for read really out to
not fail, so ERRCODE_DATA_CORRUPTED seems adapted for all of them to
me instead of ERRCODE_INTERNAL_ERROR. Or would we want to create new
sub categories for corruptions? I can personally live with
ERRCODE_DATA_CORRUPTED but..

By the way, the original PANIC message in StartupReplicationOrigin also
lacked an errcode, so fixed on the way.

BTW, isn't the initial "errno = 0" dead code now?

Hm. I have not bothered touching those as it could be possible that
read() may not initialize errno to 0, so errno would remain set to any
previous value when less bytes than expected are read, no? It seems to
me that the current coding is more careful.

Attached are two patches:
- 0001 is the previous patch with a commit messages.
- 0002 is an answer to Tom's remark about errcodes in the new error
messages for read(). I have left out the error messages for 2PC, which
are WARNINGs (those should actually be ERROR, promoted to FATAL in the
startup process, see here: https://commitfest.postgresql.org/19/1717/).
--
Michael

Attachments:

0001-Make-more-consistent-some-error-messages-for-file-re.patchtext/x-diff; charset=us-asciiDownload
From fe7d96937223fcd309c9ec102712f9335cc0af28 Mon Sep 17 00:00:00 2001
From: Michael Paquier <michael@paquier.xyz>
Date: Thu, 19 Jul 2018 11:37:29 +0900
Subject: [PATCH 1/2] Make more consistent some error messages for file-related
 operations

Some error messages which report something about a file operation use
some context which is already provided within the path being worked on,
making things duplicated.  This creates more work for translators, and
does not actually bring clarity.

More could be done, however in a lot of cases the context used is
actually useful, still that patch cuts things nicely.
---
 .../pg_stat_statements/pg_stat_statements.c   | 32 +++++++--------
 src/backend/access/transam/xlog.c             | 39 +++++++++++--------
 src/bin/pg_basebackup/pg_recvlogical.c        |  2 +-
 3 files changed, 39 insertions(+), 34 deletions(-)

diff --git a/contrib/pg_stat_statements/pg_stat_statements.c b/contrib/pg_stat_statements/pg_stat_statements.c
index cc9efab243..33f9a79f54 100644
--- a/contrib/pg_stat_statements/pg_stat_statements.c
+++ b/contrib/pg_stat_statements/pg_stat_statements.c
@@ -642,19 +642,19 @@ pgss_shmem_startup(void)
 read_error:
 	ereport(LOG,
 			(errcode_for_file_access(),
-			 errmsg("could not read pg_stat_statement file \"%s\": %m",
+			 errmsg("could not read file \"%s\": %m",
 					PGSS_DUMP_FILE)));
 	goto fail;
 data_error:
 	ereport(LOG,
 			(errcode(ERRCODE_INVALID_PARAMETER_VALUE),
-			 errmsg("ignoring invalid data in pg_stat_statement file \"%s\"",
+			 errmsg("ignoring invalid data in file \"%s\"",
 					PGSS_DUMP_FILE)));
 	goto fail;
 write_error:
 	ereport(LOG,
 			(errcode_for_file_access(),
-			 errmsg("could not write pg_stat_statement file \"%s\": %m",
+			 errmsg("could not write file \"%s\": %m",
 					PGSS_TEXT_FILE)));
 fail:
 	if (buffer)
@@ -761,7 +761,7 @@ pgss_shmem_shutdown(int code, Datum arg)
 error:
 	ereport(LOG,
 			(errcode_for_file_access(),
-			 errmsg("could not write pg_stat_statement file \"%s\": %m",
+			 errmsg("could not write file \"%s\": %m",
 					PGSS_DUMP_FILE ".tmp")));
 	if (qbuffer)
 		free(qbuffer);
@@ -1871,7 +1871,7 @@ qtext_store(const char *query, int query_len,
 error:
 	ereport(LOG,
 			(errcode_for_file_access(),
-			 errmsg("could not write pg_stat_statement file \"%s\": %m",
+			 errmsg("could not write file \"%s\": %m",
 					PGSS_TEXT_FILE)));
 
 	if (fd >= 0)
@@ -1913,7 +1913,7 @@ qtext_load_file(Size *buffer_size)
 		if (errno != ENOENT)
 			ereport(LOG,
 					(errcode_for_file_access(),
-					 errmsg("could not read pg_stat_statement file \"%s\": %m",
+					 errmsg("could not read file \"%s\": %m",
 							PGSS_TEXT_FILE)));
 		return NULL;
 	}
@@ -1923,7 +1923,7 @@ qtext_load_file(Size *buffer_size)
 	{
 		ereport(LOG,
 				(errcode_for_file_access(),
-				 errmsg("could not stat pg_stat_statement file \"%s\": %m",
+				 errmsg("could not stat file \"%s\": %m",
 						PGSS_TEXT_FILE)));
 		CloseTransientFile(fd);
 		return NULL;
@@ -1939,7 +1939,7 @@ qtext_load_file(Size *buffer_size)
 		ereport(LOG,
 				(errcode(ERRCODE_OUT_OF_MEMORY),
 				 errmsg("out of memory"),
-				 errdetail("Could not allocate enough memory to read pg_stat_statement file \"%s\".",
+				 errdetail("Could not allocate enough memory to read file \"%s\".",
 						   PGSS_TEXT_FILE)));
 		CloseTransientFile(fd);
 		return NULL;
@@ -1958,7 +1958,7 @@ qtext_load_file(Size *buffer_size)
 		if (errno)
 			ereport(LOG,
 					(errcode_for_file_access(),
-					 errmsg("could not read pg_stat_statement file \"%s\": %m",
+					 errmsg("could not read file \"%s\": %m",
 							PGSS_TEXT_FILE)));
 		free(buf);
 		CloseTransientFile(fd);
@@ -2088,7 +2088,7 @@ gc_qtexts(void)
 	{
 		ereport(LOG,
 				(errcode_for_file_access(),
-				 errmsg("could not write pg_stat_statement file \"%s\": %m",
+				 errmsg("could not write file \"%s\": %m",
 						PGSS_TEXT_FILE)));
 		goto gc_fail;
 	}
@@ -2118,7 +2118,7 @@ gc_qtexts(void)
 		{
 			ereport(LOG,
 					(errcode_for_file_access(),
-					 errmsg("could not write pg_stat_statement file \"%s\": %m",
+					 errmsg("could not write file \"%s\": %m",
 							PGSS_TEXT_FILE)));
 			hash_seq_term(&hash_seq);
 			goto gc_fail;
@@ -2136,14 +2136,14 @@ gc_qtexts(void)
 	if (ftruncate(fileno(qfile), extent) != 0)
 		ereport(LOG,
 				(errcode_for_file_access(),
-				 errmsg("could not truncate pg_stat_statement file \"%s\": %m",
+				 errmsg("could not truncate file \"%s\": %m",
 						PGSS_TEXT_FILE)));
 
 	if (FreeFile(qfile))
 	{
 		ereport(LOG,
 				(errcode_for_file_access(),
-				 errmsg("could not write pg_stat_statement file \"%s\": %m",
+				 errmsg("could not write file \"%s\": %m",
 						PGSS_TEXT_FILE)));
 		qfile = NULL;
 		goto gc_fail;
@@ -2203,7 +2203,7 @@ gc_fail:
 	if (qfile == NULL)
 		ereport(LOG,
 				(errcode_for_file_access(),
-				 errmsg("could not write new pg_stat_statement file \"%s\": %m",
+				 errmsg("could not recreate file \"%s\": %m",
 						PGSS_TEXT_FILE)));
 	else
 		FreeFile(qfile);
@@ -2255,7 +2255,7 @@ entry_reset(void)
 	{
 		ereport(LOG,
 				(errcode_for_file_access(),
-				 errmsg("could not create pg_stat_statement file \"%s\": %m",
+				 errmsg("could not create file \"%s\": %m",
 						PGSS_TEXT_FILE)));
 		goto done;
 	}
@@ -2264,7 +2264,7 @@ entry_reset(void)
 	if (ftruncate(fileno(qfile), 0) != 0)
 		ereport(LOG,
 				(errcode_for_file_access(),
-				 errmsg("could not truncate pg_stat_statement file \"%s\": %m",
+				 errmsg("could not truncate file \"%s\": %m",
 						PGSS_TEXT_FILE)));
 
 	FreeFile(qfile);
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index 3ee6d5c467..9f8ae9dc75 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -3569,7 +3569,7 @@ XLogFileOpen(XLogSegNo segno)
 	if (fd < 0)
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not open write-ahead log file \"%s\": %m", path)));
+				 errmsg("could not open file \"%s\": %m", path)));
 
 	return fd;
 }
@@ -3758,7 +3758,7 @@ XLogFileClose(void)
 	if (close(openLogFile))
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not close log file %s: %m",
+				 errmsg("could not close file \"%s\": %m",
 						XLogFileNameP(ThisTimeLineID, openLogSegNo))));
 	openLogFile = -1;
 }
@@ -4092,7 +4092,7 @@ RemoveXlogFile(const char *segname, XLogRecPtr PriorRedoPtr, XLogRecPtr endptr)
 		{
 			ereport(LOG,
 					(errcode_for_file_access(),
-					 errmsg("could not rename old write-ahead log file \"%s\": %m",
+					 errmsg("could not rename file \"%s\": %m",
 							path)));
 			return;
 		}
@@ -4502,7 +4502,7 @@ WriteControlFile(void)
 	if (fd < 0)
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not create control file \"%s\": %m",
+				 errmsg("could not create file \"%s\": %m",
 						XLOG_CONTROL_FILE)));
 
 	errno = 0;
@@ -4514,7 +4514,8 @@ WriteControlFile(void)
 			errno = ENOSPC;
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not write to control file: %m")));
+				 errmsg("could not write to file \"%s\": %m",
+						XLOG_CONTROL_FILE)));
 	}
 	pgstat_report_wait_end();
 
@@ -4522,13 +4523,15 @@ WriteControlFile(void)
 	if (pg_fsync(fd) != 0)
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not fsync control file: %m")));
+				 errmsg("could not fsync file \"%s\": %m",
+						XLOG_CONTROL_FILE)));
 	pgstat_report_wait_end();
 
 	if (close(fd))
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not close control file: %m")));
+				 errmsg("could not close file \"%s\": %m",
+						XLOG_CONTROL_FILE)));
 }
 
 static void
@@ -4758,8 +4761,7 @@ UpdateControlFile(void)
 	if (fd < 0)
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not open control file \"%s\": %m",
-						XLOG_CONTROL_FILE)));
+				 errmsg("could not open file \"%s\": %m", XLOG_CONTROL_FILE)));
 
 	errno = 0;
 	pgstat_report_wait_start(WAIT_EVENT_CONTROL_FILE_WRITE_UPDATE);
@@ -4770,7 +4772,8 @@ UpdateControlFile(void)
 			errno = ENOSPC;
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not write to control file: %m")));
+				 errmsg("could not write to file \"%s\": %m",
+						XLOG_CONTROL_FILE)));
 	}
 	pgstat_report_wait_end();
 
@@ -4778,13 +4781,15 @@ UpdateControlFile(void)
 	if (pg_fsync(fd) != 0)
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not fsync control file: %m")));
+				 errmsg("could not fsync file \"%s\": %m",
+						XLOG_CONTROL_FILE)));
 	pgstat_report_wait_end();
 
 	if (close(fd))
 		ereport(PANIC,
 				(errcode_for_file_access(),
-				 errmsg("could not close control file: %m")));
+				 errmsg("could not close file \"%s\": %m",
+						XLOG_CONTROL_FILE)));
 }
 
 /*
@@ -5684,7 +5689,7 @@ exitArchiveRecovery(TimeLineID endTLI, XLogRecPtr endOfLog)
 		if (close(fd))
 			ereport(ERROR,
 					(errcode_for_file_access(),
-					 errmsg("could not close log file %s: %m",
+					 errmsg("could not close file \"%s\": %m",
 							XLogFileNameP(ThisTimeLineID, startLogSegNo))));
 	}
 
@@ -10250,7 +10255,7 @@ assign_xlog_sync_method(int new_sync_method, void *extra)
 			if (pg_fsync(openLogFile) != 0)
 				ereport(PANIC,
 						(errcode_for_file_access(),
-						 errmsg("could not fsync log segment %s: %m",
+						 errmsg("could not fsync file \"%s\": %m",
 								XLogFileNameP(ThisTimeLineID, openLogSegNo))));
 			pgstat_report_wait_end();
 			if (get_sync_bit(sync_method) != get_sync_bit(new_sync_method))
@@ -10276,7 +10281,7 @@ issue_xlog_fsync(int fd, XLogSegNo segno)
 			if (pg_fsync_no_writethrough(fd) != 0)
 				ereport(PANIC,
 						(errcode_for_file_access(),
-						 errmsg("could not fsync log file %s: %m",
+						 errmsg("could not fsync file \"%s\": %m",
 								XLogFileNameP(ThisTimeLineID, segno))));
 			break;
 #ifdef HAVE_FSYNC_WRITETHROUGH
@@ -10284,7 +10289,7 @@ issue_xlog_fsync(int fd, XLogSegNo segno)
 			if (pg_fsync_writethrough(fd) != 0)
 				ereport(PANIC,
 						(errcode_for_file_access(),
-						 errmsg("could not fsync write-through log file %s: %m",
+						 errmsg("could not fsync write-through file \"%s\": %m",
 								XLogFileNameP(ThisTimeLineID, segno))));
 			break;
 #endif
@@ -10293,7 +10298,7 @@ issue_xlog_fsync(int fd, XLogSegNo segno)
 			if (pg_fdatasync(fd) != 0)
 				ereport(PANIC,
 						(errcode_for_file_access(),
-						 errmsg("could not fdatasync log file %s: %m",
+						 errmsg("could not fdatasync file \"%s\": %m",
 								XLogFileNameP(ThisTimeLineID, segno))));
 			break;
 #endif
diff --git a/src/bin/pg_basebackup/pg_recvlogical.c b/src/bin/pg_basebackup/pg_recvlogical.c
index ef85c9af4c..a242e0be88 100644
--- a/src/bin/pg_basebackup/pg_recvlogical.c
+++ b/src/bin/pg_basebackup/pg_recvlogical.c
@@ -197,7 +197,7 @@ OutputFsync(TimestampTz now)
 	if (fsync(outfd) != 0)
 	{
 		fprintf(stderr,
-				_("%s: could not fsync log file \"%s\": %s\n"),
+				_("%s: could not fsync file \"%s\": %s\n"),
 				progname, outfile, strerror(errno));
 		return false;
 	}
-- 
2.18.0

0002-Add-proper-errcodes-to-new-error-messages-for-read-f.patchtext/x-diff; charset=us-asciiDownload
From d01e42456778bb0247bc7471040b0d1cd5437ee5 Mon Sep 17 00:00:00 2001
From: Michael Paquier <michael@paquier.xyz>
Date: Thu, 19 Jul 2018 12:08:30 +0900
Subject: [PATCH 2/2] Add proper errcodes to new error messages for read()
 failures

Those would use the default ERRCODE_INTERNAL_ERROR, but for foreseeable
failures an errcode ought to be set, ERRCODE_DATA_CORRUPTED making the
most sense here.

Per complain from Tom Lane.
---
 src/backend/access/transam/xlog.c           |  9 ++++++---
 src/backend/replication/logical/origin.c    |  6 ++++--
 src/backend/replication/logical/snapbuild.c | 12 ++++++++----
 src/backend/replication/slot.c              |  6 ++++--
 src/backend/replication/walsender.c         |  6 ++++--
 src/backend/utils/cache/relmapper.c         |  3 ++-
 src/common/controldata_utils.c              |  3 ++-
 7 files changed, 30 insertions(+), 15 deletions(-)

diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index 9f8ae9dc75..db34349a24 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -3424,7 +3424,8 @@ XLogFileCopy(XLogSegNo destsegno, TimeLineID srcTLI, XLogSegNo srcsegno,
 									path)));
 				else
 					ereport(ERROR,
-							(errmsg("could not read file \"%s\": read %d of %zu",
+							(errcode(ERRCODE_DATA_CORRUPTED),
+							 errmsg("could not read file \"%s\": read %d of %zu",
 									path, r, (Size) nread)));
 			}
 			pgstat_report_wait_end();
@@ -4564,7 +4565,8 @@ ReadControlFile(void)
 							XLOG_CONTROL_FILE)));
 		else
 			ereport(PANIC,
-					(errmsg("could not read file \"%s\": read %d of %zu",
+					(errcode(ERRCODE_DATA_CORRUPTED),
+					 errmsg("could not read file \"%s\": read %d of %zu",
 							XLOG_CONTROL_FILE, r, sizeof(ControlFileData))));
 	}
 	pgstat_report_wait_end();
@@ -11829,7 +11831,8 @@ retry:
 		}
 		else
 			ereport(emode_for_corrupt_record(emode, targetPagePtr + reqLen),
-					(errmsg("could not read from log segment %s, offset %u: read %d of %zu",
+					(errcode(ERRCODE_DATA_CORRUPTED),
+					 errmsg("could not read from log segment %s, offset %u: read %d of %zu",
 							fname, readOff, r, (Size) XLOG_BLCKSZ)));
 		goto next_record_is_invalid;
 	}
diff --git a/src/backend/replication/logical/origin.c b/src/backend/replication/logical/origin.c
index 2d05d04b87..822c96d1c2 100644
--- a/src/backend/replication/logical/origin.c
+++ b/src/backend/replication/logical/origin.c
@@ -715,11 +715,13 @@ StartupReplicationOrigin(void)
 	{
 		if (readBytes < 0)
 			ereport(PANIC,
-					(errmsg("could not read file \"%s\": %m",
+					(errcode_for_file_access(),
+					 errmsg("could not read file \"%s\": %m",
 							path)));
 		else
 			ereport(PANIC,
-					(errmsg("could not read file \"%s\": read %d of %zu",
+					(errcode(ERRCODE_DATA_CORRUPTED),
+					 errmsg("could not read file \"%s\": read %d of %zu",
 							path, readBytes, sizeof(magic))));
 	}
 	COMP_CRC32C(crc, &magic, sizeof(magic));
diff --git a/src/backend/replication/logical/snapbuild.c b/src/backend/replication/logical/snapbuild.c
index 7bd969b0a1..1359d9b20a 100644
--- a/src/backend/replication/logical/snapbuild.c
+++ b/src/backend/replication/logical/snapbuild.c
@@ -1736,7 +1736,8 @@ SnapBuildRestore(SnapBuild *builder, XLogRecPtr lsn)
 		}
 		else
 			ereport(ERROR,
-					(errmsg("could not read file \"%s\": read %d of %zu",
+					(errcode(ERRCODE_DATA_CORRUPTED),
+					 errmsg("could not read file \"%s\": read %d of %zu",
 							path, readBytes,
 							(Size) SnapBuildOnDiskConstantSize)));
 	}
@@ -1775,7 +1776,8 @@ SnapBuildRestore(SnapBuild *builder, XLogRecPtr lsn)
 		}
 		else
 			ereport(ERROR,
-					(errmsg("could not read file \"%s\": read %d of %zu",
+					(errcode(ERRCODE_DATA_CORRUPTED),
+					 errmsg("could not read file \"%s\": read %d of %zu",
 							path, readBytes, sizeof(SnapBuild))));
 	}
 	COMP_CRC32C(checksum, &ondisk.builder, sizeof(SnapBuild));
@@ -1802,7 +1804,8 @@ SnapBuildRestore(SnapBuild *builder, XLogRecPtr lsn)
 		}
 		else
 			ereport(ERROR,
-					(errmsg("could not read file \"%s\": read %d of %zu",
+					(errcode(ERRCODE_DATA_CORRUPTED),
+					 errmsg("could not read file \"%s\": read %d of %zu",
 							path, readBytes, sz)));
 	}
 	COMP_CRC32C(checksum, ondisk.builder.was_running.was_xip, sz);
@@ -1828,7 +1831,8 @@ SnapBuildRestore(SnapBuild *builder, XLogRecPtr lsn)
 		}
 		else
 			ereport(ERROR,
-					(errmsg("could not read file \"%s\": read %d of %zu",
+					(errcode(ERRCODE_DATA_CORRUPTED),
+					 errmsg("could not read file \"%s\": read %d of %zu",
 							path, readBytes, sz)));
 	}
 	COMP_CRC32C(checksum, ondisk.builder.committed.xip, sz);
diff --git a/src/backend/replication/slot.c b/src/backend/replication/slot.c
index 271af08572..6c36398058 100644
--- a/src/backend/replication/slot.c
+++ b/src/backend/replication/slot.c
@@ -1420,7 +1420,8 @@ RestoreSlotFromDisk(const char *name)
 					 errmsg("could not read file \"%s\": %m", path)));
 		else
 			ereport(PANIC,
-					(errmsg("could not read file \"%s\": read %d of %zu",
+					(errcode(ERRCODE_DATA_CORRUPTED),
+					 errmsg("could not read file \"%s\": read %d of %zu",
 							path, readBytes,
 							(Size) ReplicationSlotOnDiskConstantSize)));
 	}
@@ -1464,7 +1465,8 @@ RestoreSlotFromDisk(const char *name)
 					 errmsg("could not read file \"%s\": %m", path)));
 		else
 			ereport(PANIC,
-					(errmsg("could not read file \"%s\": read %d of %zu",
+					(errcode(ERRCODE_DATA_CORRUPTED),
+					 errmsg("could not read file \"%s\": read %d of %zu",
 							path, readBytes, (Size) cp.length)));
 	}
 
diff --git a/src/backend/replication/walsender.c b/src/backend/replication/walsender.c
index e8f4f37e5c..d60026dfd1 100644
--- a/src/backend/replication/walsender.c
+++ b/src/backend/replication/walsender.c
@@ -509,7 +509,8 @@ SendTimeLineHistory(TimeLineHistoryCmd *cmd)
 							path)));
 		else if (nread == 0)
 			ereport(ERROR,
-					(errmsg("could not read file \"%s\": read %d of %zu",
+					(errcode(ERRCODE_DATA_CORRUPTED),
+					 errmsg("could not read file \"%s\": read %d of %zu",
 							path, nread, (Size) bytesleft)));
 
 		pq_sendbytes(&buf, rbuf, nread);
@@ -2442,7 +2443,8 @@ retry:
 		else if (readbytes == 0)
 		{
 			ereport(ERROR,
-					(errmsg("could not read from log segment %s, offset %u: read %d of %zu",
+					(errcode(ERRCODE_DATA_CORRUPTED),
+					 errmsg("could not read from log segment %s, offset %u: read %d of %zu",
 							XLogFileNameP(curFileTimeLine, sendSegNo),
 							sendOff, readbytes, (Size) segbytes)));
 		}
diff --git a/src/backend/utils/cache/relmapper.c b/src/backend/utils/cache/relmapper.c
index 2d31f9f912..c7f0e6f6d4 100644
--- a/src/backend/utils/cache/relmapper.c
+++ b/src/backend/utils/cache/relmapper.c
@@ -669,7 +669,8 @@ load_relmap_file(bool shared)
 					 errmsg("could not read file \"%s\": %m", mapfilename)));
 		else
 			ereport(FATAL,
-					(errmsg("could not read file \"%s\": read %d of %zu",
+					(errcode(ERRCODE_DATA_CORRUPTED),
+					 errmsg("could not read file \"%s\": read %d of %zu",
 							mapfilename, r, sizeof(RelMapFile))));
 	}
 	pgstat_report_wait_end();
diff --git a/src/common/controldata_utils.c b/src/common/controldata_utils.c
index 60197b2440..e24af48f52 100644
--- a/src/common/controldata_utils.c
+++ b/src/common/controldata_utils.c
@@ -83,7 +83,8 @@ get_controlfile(const char *DataDir, const char *progname, bool *crc_ok_p)
 		else
 #ifndef FRONTEND
 			ereport(ERROR,
-					(errmsg("could not read file \"%s\": read %d of %zu",
+					(errcode(ERRCODE_DATA_CORRUPTED),
+					 errmsg("could not read file \"%s\": read %d of %zu",
 							ControlFilePath, r, sizeof(ControlFileData))));
 #else
 		{
-- 
2.18.0

#4Tom Lane
tgl@sss.pgh.pa.us
In reply to: Michael Paquier (#3)
Re: More consistency for some file-related error message

Michael Paquier <michael@paquier.xyz> writes:

On Wed, Jul 18, 2018 at 10:57:16AM -0400, Tom Lane wrote:

BTW, isn't the initial "errno = 0" dead code now?

Hm. I have not bothered touching those as it could be possible that
read() may not initialize errno to 0, so errno would remain set to any
previous value when less bytes than expected are read, no? It seems to
me that the current coding is more careful.

read() is required by spec to set errno when returning a negative result.
I think the previous coding paid attention to errno regardless of the sign
of the result, which would justify pre-zeroing it ... but the new coding
definitely doesn't.

regards, tom lane

#5Michael Paquier
michael@paquier.xyz
In reply to: Tom Lane (#4)
Re: More consistency for some file-related error message

On Wed, Jul 18, 2018 at 11:24:05PM -0400, Tom Lane wrote:

read() is required by spec to set errno when returning a negative result.
I think the previous coding paid attention to errno regardless of the sign
of the result, which would justify pre-zeroing it ... but the new coding
definitely doesn't.

Yes, my point is a bit different though.. Do you think that we need to
bother about the case where errno is not 0 before calling read(), in the
case where it returns a positive result? This would mean that errno
would still have a previous errno set, still it returned a number of
bytes read. For the code paths discussed here that visibly does not
matter so you are right, we could remove them, still patterns get easily
copy-pasted around...
--
Michael

#6Kyotaro HORIGUCHI
horiguchi.kyotaro@lab.ntt.co.jp
In reply to: Michael Paquier (#5)
Re: More consistency for some file-related error message

Hello.

At Thu, 19 Jul 2018 12:33:30 +0900, Michael Paquier <michael@paquier.xyz> wrote in <20180719033330.GH3411@paquier.xyz>

On Wed, Jul 18, 2018 at 11:24:05PM -0400, Tom Lane wrote:

read() is required by spec to set errno when returning a negative result.
I think the previous coding paid attention to errno regardless of the sign
of the result, which would justify pre-zeroing it ... but the new coding
definitely doesn't.

Yes, my point is a bit different though.. Do you think that we need to
bother about the case where errno is not 0 before calling read(), in the
case where it returns a positive result? This would mean that errno
would still have a previous errno set, still it returned a number of
bytes read. For the code paths discussed here that visibly does not
matter so you are right, we could remove them, still patterns get easily
copy-pasted around...

Agreed to it's not necessary and a developer ought to know about
the errno behavior. However, I can sympathize with Michael.

Meawhile I found the following code in xlog.c.

| r = fread(labelfile, statbuf.st_size, 1, lfp);
| labelfile[statbuf.st_size] = '\0';
|
| /*
| * Close and remove the backup label file
| */
| if (r != 1 || ferror(lfp) || FreeFile(lfp))
| ereport(ERROR,
| (errcode_for_file_access(),
| errmsg("could not read file \"%s\": %m",
| BACKUP_LABEL_FILE)));

fread() and ferror() don't set errno so the
errcode_for_file_access() gives a bogus result. The same found in
basebackup.c and genfile.c. Also found in bootscanner.c but it
doesn't come from .l file..

CopyGetData has a variant of it.

| bytesread = fread(databuf, 1, maxread, cstate->copy_file);
| if (ferror(cstate->copy_file))
| ereport(ERROR,
| (errcode_for_file_access(),

ereport(..(errcode_for_file_access() gets bogus errno here.

Might be trivial but the following message is emitted for
AllocateFile failure and AllocateFile feilure in other places
gets a different message "could not *open* file". The differece
leads to a slightly confusing message which doesn't harm so much
like "could not read file: File name too long"..

| - errmsg("could not read pg_stat_statement file \"%s\": %m",
| + errmsg("could not read file \"%s\": %m",

And I see other variants of this like the follows.

"could not read from hash-join temporary file: %m"
"could not read two-phase state file \"%s\": %m"
"could not read from COPY file: %m"

I'm not sure it's a good thing to elimiate all specific file naem
from all of these but I don't find a criteria whether we use
generic or specific message in each case.

About the following and similars, there's two variants which has
"to" and not has it.

| - errmsg("could not write pg_stat_statement file \"%s\": %m",
| + errmsg("could not write file \"%s\": %m",

| - errmsg("could not write to control file: %m")));
| + errmsg("could not write to file \"%s\": %m",

regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center

#7Michael Paquier
michael@paquier.xyz
In reply to: Kyotaro HORIGUCHI (#6)
Re: More consistency for some file-related error message

On Thu, Jul 19, 2018 at 02:05:51PM +0900, Kyotaro HORIGUCHI wrote:

Agreed to it's not necessary and a developer ought to know about
the errno behavior. However, I can sympathize with Michael.

I am fine to remove them if folks here push for that.

CopyGetData has a variant of it.

| bytesread = fread(databuf, 1, maxread, cstate->copy_file);
| if (ferror(cstate->copy_file))
| ereport(ERROR,
| (errcode_for_file_access(),

ereport(..(errcode_for_file_access() gets bogus errno here.

Yeah, I saw those but did not really bother much about them yet, errno
should be set to the return result of ferror(). If you have a patch,
please feel free to send one.

And I see other variants of this like the follows.

"could not read from hash-join temporary file: %m"
"could not read from COPY file: %m"

This is intentional. You may not be able to guess the context based on
the file name.

"could not read two-phase state file \"%s\": %m"

You need to refresh your tree, that does not show up on HEAD anymore.
See 811b6e3.

I'm not sure it's a good thing to elimiate all specific file naem
from all of these but I don't find a criteria whether we use
generic or specific message in each case.

I would say that we can remove any context-specific message if one can
guess easily based on the file name what the context is. For two phase
files, that's for example easy as pg_twophase/ is involved.

About the following and similars, there's two variants which has
"to" and not has it.

| - errmsg("could not write pg_stat_statement file \"%s\": %m",
| + errmsg("could not write file \"%s\": %m",

| - errmsg("could not write to control file: %m")));
| + errmsg("could not write to file \"%s\": %m",

It seems to me that it is important to make the distinction between a
file which gets fully written and a file which exists already and gets
written more. That's this difference I understand from these two
error messages, so that's my intention to not change them.
--
Michael

#8Michael Paquier
michael@paquier.xyz
In reply to: Michael Paquier (#5)
Re: More consistency for some file-related error message

On Thu, Jul 19, 2018 at 12:33:30PM +0900, Michael Paquier wrote:

On Wed, Jul 18, 2018 at 11:24:05PM -0400, Tom Lane wrote:

read() is required by spec to set errno when returning a negative result.
I think the previous coding paid attention to errno regardless of the sign
of the result, which would justify pre-zeroing it ... but the new coding
definitely doesn't.

Yes, my point is a bit different though.. Do you think that we need to
bother about the case where errno is not 0 before calling read(), in the
case where it returns a positive result? This would mean that errno
would still have a previous errno set, still it returned a number of
bytes read. For the code paths discussed here that visibly does not
matter so you are right, we could remove them, still patterns get easily
copy-pasted around...

Okay, I just looked again at this point, and among the new messages only
what's in XLogFileCopy has been bothering setting errno to 0 (see
811b6e3), so let's remove it in this case.

Thoughts about the previous patch set?
--
Michael

#9Michael Paquier
michael@paquier.xyz
In reply to: Michael Paquier (#8)
Re: More consistency for some file-related error message

On Fri, Jul 20, 2018 at 03:41:08PM +0900, Michael Paquier wrote:

Okay, I just looked again at this point, and among the new messages only
what's in XLogFileCopy has been bothering setting errno to 0 (see
811b6e3), so let's remove it in this case.

So, I have been through the patch set once again and pushed the patch to
make more error messages consistent, as well as the patch to set up
proper errcodes for new error messages. There are perhaps more
improvements which could be done for the error messages, but that's not
absolutely clear either as the context used is actually useful in those
remaining.
--
Michael