Location via proxy:   [ UP ]  
[Report a bug]   [Manage cookies]                
Skip to content

Commit 789b938

Browse files
committed
Centralize logic for skipping useless ereport/elog calls.
While ereport() and elog() themselves are quite cheap when the error message level is too low to be printed, some places need to do substantial work before they can call those macros at all. To allow optimizing away such setup work when nothing is to be printed, make elog.c export a new function message_level_is_interesting(elevel) that reports whether ereport/elog will do anything. Make use of that in various places that had ad-hoc direct tests of log_min_messages etc. Also teach ProcSleep to use it to avoid some work. (There may well be other places that could usefully use this; I didn't search hard.) Within elog.c, refactor a little bit to avoid having duplicate copies of the policy-setting logic. When that code was written, we weren't relying on the availability of inline functions; so it had some duplications in the name of efficiency, which I got rid of. Alvaro Herrera and Tom Lane Discussion: https://postgr.es/m/129515.1606166429@sss.pgh.pa.us
1 parent 1fa22a4 commit 789b938

File tree

8 files changed

+126
-94
lines changed

8 files changed

+126
-94
lines changed

src/backend/access/transam/xact.c

+1-2
Original file line numberDiff line numberDiff line change
@@ -5344,7 +5344,7 @@ static void
53445344
ShowTransactionState(const char *str)
53455345
{
53465346
/* skip work if message will definitely not be printed */
5347-
if (log_min_messages <= DEBUG5 || client_min_messages <= DEBUG5)
5347+
if (message_level_is_interesting(DEBUG5))
53485348
ShowTransactionStateRec(str, CurrentTransactionState);
53495349
}
53505350

@@ -5371,7 +5371,6 @@ ShowTransactionStateRec(const char *str, TransactionState s)
53715371
if (s->parent)
53725372
ShowTransactionStateRec(str, s->parent);
53735373

5374-
/* use ereport to suppress computation if msg will not be printed */
53755374
ereport(DEBUG5,
53765375
(errmsg_internal("%s(%d) name: %s; blockState: %s; state: %s, xid/subid/cid: %u/%u/%u%s%s",
53775376
str, s->nestingLevel,

src/backend/access/transam/xlogutils.c

+3-3
Original file line numberDiff line numberDiff line change
@@ -105,7 +105,7 @@ log_invalid_page(RelFileNode node, ForkNumber forkno, BlockNumber blkno,
105105
* tracing of the cause (note the elog context mechanism will tell us
106106
* something about the XLOG record that generated the reference).
107107
*/
108-
if (log_min_messages <= DEBUG1 || client_min_messages <= DEBUG1)
108+
if (message_level_is_interesting(DEBUG1))
109109
report_invalid_page(DEBUG1, node, forkno, blkno, present);
110110

111111
if (invalid_page_tab == NULL)
@@ -159,7 +159,7 @@ forget_invalid_pages(RelFileNode node, ForkNumber forkno, BlockNumber minblkno)
159159
hentry->key.forkno == forkno &&
160160
hentry->key.blkno >= minblkno)
161161
{
162-
if (log_min_messages <= DEBUG2 || client_min_messages <= DEBUG2)
162+
if (message_level_is_interesting(DEBUG2))
163163
{
164164
char *path = relpathperm(hentry->key.node, forkno);
165165

@@ -192,7 +192,7 @@ forget_invalid_pages_db(Oid dbid)
192192
{
193193
if (hentry->key.node.dbNode == dbid)
194194
{
195-
if (log_min_messages <= DEBUG2 || client_min_messages <= DEBUG2)
195+
if (message_level_is_interesting(DEBUG2))
196196
{
197197
char *path = relpathperm(hentry->key.node, hentry->key.forkno);
198198

src/backend/catalog/dependency.c

+1-7
Original file line numberDiff line numberDiff line change
@@ -1146,15 +1146,9 @@ reportDependentObjects(const ObjectAddresses *targetObjects,
11461146
* If no error is to be thrown, and the msglevel is too low to be shown to
11471147
* either client or server log, there's no need to do any of the rest of
11481148
* the work.
1149-
*
1150-
* Note: this code doesn't know all there is to be known about elog
1151-
* levels, but it works for NOTICE and DEBUG2, which are the only values
1152-
* msglevel can currently have. We also assume we are running in a normal
1153-
* operating environment.
11541149
*/
11551150
if (behavior == DROP_CASCADE &&
1156-
msglevel < client_min_messages &&
1157-
(msglevel < log_min_messages || log_min_messages == LOG))
1151+
!message_level_is_interesting(msglevel))
11581152
return;
11591153

11601154
/*

src/backend/replication/walreceiver.c

+1-1
Original file line numberDiff line numberDiff line change
@@ -1215,7 +1215,7 @@ ProcessWalSndrMessage(XLogRecPtr walEnd, TimestampTz sendTime)
12151215
walrcv->lastMsgReceiptTime = lastMsgReceiptTime;
12161216
SpinLockRelease(&walrcv->mutex);
12171217

1218-
if (log_min_messages <= DEBUG2)
1218+
if (message_level_is_interesting(DEBUG2))
12191219
{
12201220
char *sendtime;
12211221
char *receipttime;

src/backend/replication/walsender.c

+2-2
Original file line numberDiff line numberDiff line change
@@ -1900,7 +1900,7 @@ ProcessStandbyReplyMessage(void)
19001900
replyTime = pq_getmsgint64(&reply_message);
19011901
replyRequested = pq_getmsgbyte(&reply_message);
19021902

1903-
if (log_min_messages <= DEBUG2)
1903+
if (message_level_is_interesting(DEBUG2))
19041904
{
19051905
char *replyTimeStr;
19061906

@@ -2082,7 +2082,7 @@ ProcessStandbyHSFeedbackMessage(void)
20822082
feedbackCatalogXmin = pq_getmsgint(&reply_message, 4);
20832083
feedbackCatalogEpoch = pq_getmsgint(&reply_message, 4);
20842084

2085-
if (log_min_messages <= DEBUG2)
2085+
if (message_level_is_interesting(DEBUG2))
20862086
{
20872087
char *replyTimeStr;
20882088

src/backend/storage/lmgr/proc.c

+22-18
Original file line numberDiff line numberDiff line change
@@ -1337,26 +1337,30 @@ ProcSleep(LOCALLOCK *locallock, LockMethod lockMethodTable)
13371337
!(statusFlags & PROC_VACUUM_FOR_WRAPAROUND))
13381338
{
13391339
int pid = autovac->pid;
1340-
StringInfoData locktagbuf;
1341-
StringInfoData logbuf; /* errdetail for server log */
13421340

13431341
/* report the case, if configured to do so */
1344-
initStringInfo(&locktagbuf);
1345-
initStringInfo(&logbuf);
1346-
DescribeLockTag(&locktagbuf, &locktag_copy);
1347-
appendStringInfo(&logbuf,
1348-
_("Process %d waits for %s on %s."),
1349-
MyProcPid,
1350-
GetLockmodeName(lockmethod_copy, lockmode),
1351-
locktagbuf.data);
1352-
1353-
ereport(DEBUG1,
1354-
(errmsg("sending cancel to blocking autovacuum PID %d",
1355-
pid),
1356-
errdetail_log("%s", logbuf.data)));
1357-
1358-
pfree(logbuf.data);
1359-
pfree(locktagbuf.data);
1342+
if (message_level_is_interesting(DEBUG1))
1343+
{
1344+
StringInfoData locktagbuf;
1345+
StringInfoData logbuf; /* errdetail for server log */
1346+
1347+
initStringInfo(&locktagbuf);
1348+
initStringInfo(&logbuf);
1349+
DescribeLockTag(&locktagbuf, &locktag_copy);
1350+
appendStringInfo(&logbuf,
1351+
_("Process %d waits for %s on %s."),
1352+
MyProcPid,
1353+
GetLockmodeName(lockmethod_copy, lockmode),
1354+
locktagbuf.data);
1355+
1356+
ereport(DEBUG1,
1357+
(errmsg("sending cancel to blocking autovacuum PID %d",
1358+
pid),
1359+
errdetail_log("%s", logbuf.data)));
1360+
1361+
pfree(locktagbuf.data);
1362+
pfree(logbuf.data);
1363+
}
13601364

13611365
/* send the autovacuum worker Back to Old Kent Road */
13621366
if (kill(pid, SIGINT) < 0)

src/backend/utils/error/elog.c

+93-60
Original file line numberDiff line numberDiff line change
@@ -184,7 +184,94 @@ static void write_pipe_chunks(char *data, int len, int dest);
184184
static void send_message_to_frontend(ErrorData *edata);
185185
static const char *error_severity(int elevel);
186186
static void append_with_tabs(StringInfo buf, const char *str);
187-
static bool is_log_level_output(int elevel, int log_min_level);
187+
188+
189+
/*
190+
* is_log_level_output -- is elevel logically >= log_min_level?
191+
*
192+
* We use this for tests that should consider LOG to sort out-of-order,
193+
* between ERROR and FATAL. Generally this is the right thing for testing
194+
* whether a message should go to the postmaster log, whereas a simple >=
195+
* test is correct for testing whether the message should go to the client.
196+
*/
197+
static inline bool
198+
is_log_level_output(int elevel, int log_min_level)
199+
{
200+
if (elevel == LOG || elevel == LOG_SERVER_ONLY)
201+
{
202+
if (log_min_level == LOG || log_min_level <= ERROR)
203+
return true;
204+
}
205+
else if (log_min_level == LOG)
206+
{
207+
/* elevel != LOG */
208+
if (elevel >= FATAL)
209+
return true;
210+
}
211+
/* Neither is LOG */
212+
else if (elevel >= log_min_level)
213+
return true;
214+
215+
return false;
216+
}
217+
218+
/*
219+
* Policy-setting subroutines. These are fairly simple, but it seems wise
220+
* to have the code in just one place.
221+
*/
222+
223+
/*
224+
* should_output_to_server --- should message of given elevel go to the log?
225+
*/
226+
static inline bool
227+
should_output_to_server(int elevel)
228+
{
229+
return is_log_level_output(elevel, log_min_messages);
230+
}
231+
232+
/*
233+
* should_output_to_client --- should message of given elevel go to the client?
234+
*/
235+
static inline bool
236+
should_output_to_client(int elevel)
237+
{
238+
if (whereToSendOutput == DestRemote && elevel != LOG_SERVER_ONLY)
239+
{
240+
/*
241+
* client_min_messages is honored only after we complete the
242+
* authentication handshake. This is required both for security
243+
* reasons and because many clients can't handle NOTICE messages
244+
* during authentication.
245+
*/
246+
if (ClientAuthInProgress)
247+
return (elevel >= ERROR);
248+
else
249+
return (elevel >= client_min_messages || elevel == INFO);
250+
}
251+
return false;
252+
}
253+
254+
255+
/*
256+
* message_level_is_interesting --- would ereport/elog do anything?
257+
*
258+
* Returns true if ereport/elog with this elevel will not be a no-op.
259+
* This is useful to short-circuit any expensive preparatory work that
260+
* might be needed for a logging message. There is no point in
261+
* prepending this to a bare ereport/elog call, however.
262+
*/
263+
bool
264+
message_level_is_interesting(int elevel)
265+
{
266+
/*
267+
* Keep this in sync with the decision-making in errstart().
268+
*/
269+
if (elevel >= ERROR ||
270+
should_output_to_server(elevel) ||
271+
should_output_to_client(elevel))
272+
return true;
273+
return false;
274+
}
188275

189276

190277
/*
@@ -301,27 +388,8 @@ errstart(int elevel, const char *domain)
301388
* warning or less and not enabled for logging, just return false without
302389
* starting up any error logging machinery.
303390
*/
304-
305-
/* Determine whether message is enabled for server log output */
306-
output_to_server = is_log_level_output(elevel, log_min_messages);
307-
308-
/* Determine whether message is enabled for client output */
309-
if (whereToSendOutput == DestRemote && elevel != LOG_SERVER_ONLY)
310-
{
311-
/*
312-
* client_min_messages is honored only after we complete the
313-
* authentication handshake. This is required both for security
314-
* reasons and because many clients can't handle NOTICE messages
315-
* during authentication.
316-
*/
317-
if (ClientAuthInProgress)
318-
output_to_client = (elevel >= ERROR);
319-
else
320-
output_to_client = (elevel >= client_min_messages ||
321-
elevel == INFO);
322-
}
323-
324-
/* Skip processing effort if non-error message will not be output */
391+
output_to_server = should_output_to_server(elevel);
392+
output_to_client = should_output_to_client(elevel);
325393
if (elevel < ERROR && !output_to_server && !output_to_client)
326394
return false;
327395

@@ -1743,16 +1811,10 @@ pg_re_throw(void)
17431811

17441812
/*
17451813
* At least in principle, the increase in severity could have changed
1746-
* where-to-output decisions, so recalculate. This should stay in
1747-
* sync with errstart(), which see for comments.
1814+
* where-to-output decisions, so recalculate.
17481815
*/
1749-
if (IsPostmasterEnvironment)
1750-
edata->output_to_server = is_log_level_output(FATAL,
1751-
log_min_messages);
1752-
else
1753-
edata->output_to_server = (FATAL >= log_min_messages);
1754-
if (whereToSendOutput == DestRemote)
1755-
edata->output_to_client = true;
1816+
edata->output_to_server = should_output_to_server(FATAL);
1817+
edata->output_to_client = should_output_to_client(FATAL);
17561818

17571819
/*
17581820
* We can use errfinish() for the rest, but we don't want it to call
@@ -3505,35 +3567,6 @@ write_stderr(const char *fmt,...)
35053567
}
35063568

35073569

3508-
/*
3509-
* is_log_level_output -- is elevel logically >= log_min_level?
3510-
*
3511-
* We use this for tests that should consider LOG to sort out-of-order,
3512-
* between ERROR and FATAL. Generally this is the right thing for testing
3513-
* whether a message should go to the postmaster log, whereas a simple >=
3514-
* test is correct for testing whether the message should go to the client.
3515-
*/
3516-
static bool
3517-
is_log_level_output(int elevel, int log_min_level)
3518-
{
3519-
if (elevel == LOG || elevel == LOG_SERVER_ONLY)
3520-
{
3521-
if (log_min_level == LOG || log_min_level <= ERROR)
3522-
return true;
3523-
}
3524-
else if (log_min_level == LOG)
3525-
{
3526-
/* elevel != LOG */
3527-
if (elevel >= FATAL)
3528-
return true;
3529-
}
3530-
/* Neither is LOG */
3531-
else if (elevel >= log_min_level)
3532-
return true;
3533-
3534-
return false;
3535-
}
3536-
35373570
/*
35383571
* Adjust the level of a recovery-related message per trace_recovery_messages.
35393572
*

src/include/utils/elog.h

+3-1
Original file line numberDiff line numberDiff line change
@@ -157,8 +157,10 @@
157157

158158
#define TEXTDOMAIN NULL
159159

160-
extern bool pg_attribute_cold errstart_cold(int elevel, const char *domain);
160+
extern bool message_level_is_interesting(int elevel);
161+
161162
extern bool errstart(int elevel, const char *domain);
163+
extern bool pg_attribute_cold errstart_cold(int elevel, const char *domain);
162164
extern void errfinish(const char *filename, int lineno, const char *funcname);
163165

164166
extern int errcode(int sqlerrcode);

0 commit comments

Comments
 (0)