Downgrading some normal ERROR messages to DEBUG messages.
authorBo Peng <pengbo@sraoss.co.jp>
Thu, 9 Nov 2023 12:52:43 +0000 (21:52 +0900)
committerBo Peng <pengbo@sraoss.co.jp>
Thu, 9 Nov 2023 12:52:43 +0000 (21:52 +0900)
The following ERROR messages are downgraded to DEBUG messages.

(1) ERROR:unable to flush data to frontend

(2) ERROR:  unable to read data from frontend
    DETAIL:  EOF encountered with frontend

(3) ERROR:  unable to read data
    DETAIL:  child connection forced to terminate due to client_idle_limit:30 is reached

(1) and (2)
These messages are cuased when the client did not send a terminate message
before disconnecting to pgpool.
For example, when the client process was forcefully terminated, the error occurs.
Although they are harmless, it can sometimes confuse users.

(3)
If we set "client_idle_limit" to a non-zero value, the connection
will be disconnected if it remains idle since the last query.

The disconnection is caused by Pgpool-II settings,
but Pgpool-II handles the log message as an "ERROR".

Because the ERROR messages above are normal messages, I decide to downgrade them.

Discussion: https://www.pgpool.net/pipermail/pgpool-hackers/2023-June/004351.html

src/include/utils/elog.h
src/include/utils/fe_ports.h
src/protocol/pool_process_query.c
src/tools/fe_port.c
src/utils/error/elog.c
src/utils/pool_stream.c

index bbe93880d95d1f908e29e7488dd38ea0e45ca2ab..5494c9618bf1c6277d6a3feed7f8a42baac604a4 100644 (file)
@@ -121,8 +121,10 @@ typedef enum
 /* pgpool-II extension. This is same as ERROR but sets the
  * do not cache connection flag before transforming to ERROR.
  */
-#define FRONTEND_ERROR                 23      /* transformed to ERROR at errstart */
-#define FRONTEND_ONLY_ERROR            24      /* this is treated as LOG message
+#define FRONTEND_DEBUG                 23      /* transformed to DEBUG at errstart */
+#define FRONTEND_LOG                   24      /* transformed to LOG at errstart */
+#define FRONTEND_ERROR                 25      /* transformed to ERROR at errstart */
+#define FRONTEND_ONLY_ERROR            26      /* this is treated as LOG message
                                                                         * internally for pgpool-II but forwarded
                                                                         * to frontend clients just like normal
                                                                         * errors followed by readyForQuery
index ddbd462d58f54fe7e4616fe8c97fc3d1b6f6f548..6b0e4889d372755e39e58c66dac6b9c92932015e 100644 (file)
@@ -113,8 +113,10 @@ extern void errfinish(int dummy,...);
 #define FATAL          21                      /* fatal error - abort process */
 #define PANIC          22                      /* take down the other backends with me */
 
-#define FRONTEND_ERROR                 23      /* transformed to ERROR at errstart */
-#define FRONTEND_ONLY_ERROR            24      /* this is treated as LOG message
+#define FRONTEND_DEBUG                 23      /* transformed to DEBUG at errstart */
+#define FRONTEND_LOG                   24      /* transformed to LOG at errstart */
+#define FRONTEND_ERROR                 25      /* transformed to ERROR at errstart */
+#define FRONTEND_ONLY_ERROR            26      /* this is treated as LOG message
                                                                         * internally for pgpool-II but forwarded
                                                                         * to frontend clients just like normal
                                                                         * errors followed by readyForQuery
index 07dcc0b1f59534c167ce38867ad879f837932ce1..fc2d22283da04b14fad1d4017e35ba785da0bb68 100644 (file)
@@ -571,8 +571,8 @@ wait_for_query_response(POOL_CONNECTION * frontend, POOL_CONNECTION * backend, i
                                pool_write(frontend, DUMMY_VALUE, sizeof(DUMMY_VALUE));
                                if (pool_flush_it(frontend) < 0)
                                {
-                                       ereport(FRONTEND_ERROR,
-                                                       (errmsg("unable to to flush data to frontend"),
+                                       ereport(FRONTEND_DEBUG,
+                                                       (errmsg("unable to flush data to frontend"),
                                                         errdetail("frontend error occurred while waiting for backend reply")));
                                }
 
@@ -595,8 +595,8 @@ wait_for_query_response(POOL_CONNECTION * frontend, POOL_CONNECTION * backend, i
                                pool_write(frontend, notice_message, strlen(notice_message) + 1);
                                if (pool_flush_it(frontend) < 0)
                                {
-                                       ereport(FRONTEND_ERROR,
-                                                       (errmsg("unable to to flush data to frontend"),
+                                       ereport(FRONTEND_DEBUG,
+                                                       (errmsg("unable to flush data to frontend"),
                                                         errdetail("frontend error occurred while waiting for backend reply")));
 
                                }
@@ -4922,7 +4922,7 @@ SELECT_RETRY:
 
                        if (idle_count > pool_config->client_idle_limit)
                        {
-                               ereport(FRONTEND_ERROR,
+                               ereport(FRONTEND_DEBUG,
                                                (pool_error_code("57000"),
                                                 errmsg("unable to read data"),
                                                 errdetail("child connection forced to terminate due to client_idle_limit:%d is reached",
@@ -4935,7 +4935,7 @@ SELECT_RETRY:
 
                        if (idle_count_in_recovery > pool_config->client_idle_limit_in_recovery)
                        {
-                               ereport(FRONTEND_ERROR,
+                               ereport(FRONTEND_DEBUG,
                                                (pool_error_code("57000"),
                                                 errmsg("unable to read data"),
                                                 errdetail("child connection forced to terminate due to client_idle_limit_in_recovery:%d is reached", pool_config->client_idle_limit_in_recovery)));
@@ -4947,7 +4947,7 @@ SELECT_RETRY:
                         * If we are in recovery and client_idle_limit_in_recovery is -1,
                         * then exit immediately.
                         */
-                       ereport(FRONTEND_ERROR,
+                       ereport(FRONTEND_DEBUG,
                                        (pool_error_code("57000"),
                                         errmsg("connection terminated due to online recovery"),
                                         errdetail("child connection forced to terminate due to client_idle_limit:-1")));
index 7c305736c6ef340e787ce5bd483a880d61441347..6b95c29c749f2e9a0ee4cac387b8e81abe7907da 100644 (file)
@@ -118,10 +118,12 @@ error_severity(int elevel)
                case DEBUG3:
                case DEBUG4:
                case DEBUG5:
+               case FRONTEND_DEBUG:
                        prefix = "DEBUG";
                        break;
                case LOG:
                case COMMERROR:
+               case FRONTEND_LOG:
                        prefix = "LOG";
                        break;
                case INFO:
index 44061c60f8363def8a3a82f363ee65097d4b4d63..9d4c14595a603ec2c49313136ebd1a5dff637999 100644 (file)
@@ -202,11 +202,16 @@ static inline bool should_output_to_client(int elevel);
 static bool
 is_log_level_output(int elevel, int log_min_level)
 {
-       if (elevel == LOG || elevel == COMMERROR || elevel == FRONTEND_ONLY_ERROR)
+       if (elevel == LOG || elevel == COMMERROR || elevel == FRONTEND_ONLY_ERROR || elevel == FRONTEND_LOG)
        {
                if (log_min_level == LOG || log_min_level <= ERROR)
                        return true;
        }
+       else if (elevel == FRONTEND_DEBUG)
+       {
+               if (log_min_level <= DEBUG1)
+                       return true;
+       }
        else if (log_min_level == LOG)
        {
                /* elevel != LOG */
@@ -313,6 +318,10 @@ errstart(int elevel, const char *filename, int lineno,
                frontend_invalid = true;
                elevel = ERROR;
        }
+       else if (elevel == FRONTEND_DEBUG || elevel == FRONTEND_LOG)
+       {
+               frontend_invalid = true;
+       }
 
        if (elevel >= ERROR && elevel != FRONTEND_ONLY_ERROR)
        {
@@ -328,7 +337,7 @@ errstart(int elevel, const char *filename, int lineno,
                 * proc_exit's responsibility to see that this doesn't turn into
                 * infinite recursion!)
                 */
-               if (elevel == ERROR)
+               if (elevel == ERROR || elevel == FRONTEND_LOG || elevel == FRONTEND_DEBUG)
                {
                        if (PG_exception_stack == NULL ||
                                proc_exit_inprogress)
@@ -477,7 +486,7 @@ errfinish(int dummy,...)
         * If ERROR (not more nor less) we pass it off to the current handler.
         * Printing it and popping the stack is the responsibility of the handler.
         */
-       if (elevel == ERROR)
+       if (elevel == ERROR || elevel == FRONTEND_LOG || elevel == FRONTEND_DEBUG)
        {
                /*
                 * We do some minimal cleanup before longjmp'ing so that handlers can
@@ -1691,6 +1700,8 @@ write_eventlog(int level, const char *line, int len)
                case DEBUG1:
                case LOG:
                case COMMERROR:
+               case FRONTEND_LOG:
+               case FRONTEND_DEBUG:
                case INFO:
                case NOTICE:
                        eventlevel = EVENTLOG_INFORMATION_TYPE;
@@ -2325,11 +2336,13 @@ send_message_to_server_log(ErrorData *edata)
                        case DEBUG3:
                        case DEBUG2:
                        case DEBUG1:
+                       case FRONTEND_DEBUG:
                                syslog_level = LOG_DEBUG;
                                break;
                        case LOG:
                        case COMMERROR:
                        case INFO:
+                       case FRONTEND_LOG:
                                syslog_level = LOG_INFO;
                                break;
                        case NOTICE:
@@ -2472,10 +2485,12 @@ error_severity(int elevel, bool for_frontend)
                case DEBUG3:
                case DEBUG4:
                case DEBUG5:
+               case FRONTEND_DEBUG:
                        prefix = _("DEBUG");
                        break;
                case LOG:
                case COMMERROR:
+               case FRONTEND_LOG:
                        prefix = _("LOG");
                        break;
                case INFO:
index 2eafd962387801c7b21be10cd47b55a0dea22a21..8ed49a730fadc1d642544f55ce8f7d468908ff97 100644 (file)
@@ -256,7 +256,7 @@ pool_read(POOL_CONNECTION * cp, void *buf, int len)
                        }
                        else
                        {
-                               ereport(FRONTEND_ERROR,
+                               ereport(FRONTEND_DEBUG,
                                                (errmsg("unable to read data from frontend"),
                                                 errdetail("socket read failed with error \"%m\"")));
                        }
@@ -281,7 +281,7 @@ pool_read(POOL_CONNECTION * cp, void *buf, int len)
                                 * if backend offers authentication method, frontend could
                                 * close connection
                                 */
-                               ereport(FRONTEND_ERROR,
+                               ereport(FRONTEND_DEBUG,
                                                (errmsg("unable to read data from frontend"),
                                                 errdetail("EOF encountered with frontend")));
                        }
@@ -776,7 +776,7 @@ pool_flush(POOL_CONNECTION * cp)
                                                (errmsg("unable to flush data to frontend"),
                                                 errdetail("pgpool is in replication mode, ignoring error to keep consistency among backends")));
                        else
-                               ereport(FRONTEND_ERROR,
+                               ereport(FRONTEND_DEBUG,
                                                (errmsg("unable to flush data to frontend")));
 
                }