[pgpool-hackers: 3787] Re: Proposal: Add log_disconnections parameter
Takuma Hoshiai
hoshiai.takuma at nttcom.co.jp
Thu Aug 20 14:45:22 JST 2020
Hi,
On 2020/08/18 17:31, Tatsuo Ishii wrote:
>> Hi Ishii-san,
>>
>> I have fixed a previous proposal patch about log_disconnections
>> paramter. A session time is added in log message.
>>
>> A previous mail is:
>> [pgpool-hackers: 3656] Re: Proposal: Add log_disconnections parameter
>>
>>
>> e.g.
>> enable log_connections and log_disconnections, and execute the
>> following query
>> psql -p 11000 test -c "SELECT pg_sleep(5)"
>>
>> == log messages ======
>> 2020-08-13 18:04:39: child pid 10830: LOG: new connection received
>> 2020-08-13 18:04:39: child pid 10830: DETAIL: connecting host=[local]
>> 2020-08-13 18:04:39: psql pid 10830: LOG: pool_reuse_block: blockid: 0
>> 2020-08-13 18:04:39: psql pid 10830: CONTEXT: while searching system
>> catalog, When relcache is missed
>> 2020-08-13 18:04:44: psql pid 10830: LOG: frontend connection closed
>> 2020-08-13 18:04:44: psql pid 10830: DETAIL: connected host=[local]
>> session time: 0:00:05.037
>> =====================
>
> Isn't it better the message format of log_disconnections matches with
> PostgreSQL's message? It's something like:
>
> ereport(LOG,
> (errmsg("disconnection: session time: %d:%02d:%02d.%03d "
> "user=%s database=%s host=%s%s%s",
> hours, minutes, seconds, msecs,
> port->user_name, port->database_name, port->remote_host,
> port->remote_port[0] ? " port=" : "", port->remote_port)));
>
> (in log_disconnections() of src/backend/tcop/postgres.c)
Thank you for your advice.I think so, too.
I reflected it to my patch.
$ psql -p 11000 test -c "SELECT pg_sleep(3);"
2020-08-20 14:16:30: psql pid 4108:LOG: new connection received
2020-08-20 14:16:30: psql pid 4108:DETAIL: connecting host=[local]
2020-08-20 14:16:33: psql pid 4108:LOG: frontend disconnection: session
time: 0:00:03.007 user=hoshiai database=test host=[local]
> Best regards,
> --
> Tatsuo Ishii
> SRA OSS, Inc. Japan
> English: http://www.sraoss.co.jp/index_en.php
> Japanese:http://www.sraoss.co.jp
>
Best Regards,
--
Takuma Hoshiai <hoshiai.takuma at nttcom.co.jp>
-------------- next part --------------
doc.ja/src/sgml/connection-pooling.sgml | 25 ++++++++++++++++
doc/src/sgml/connection-pooling.sgml | 16 +++++++++++
src/config/pool_config_variables.c | 10 +++++++
src/include/pool_config.h | 1 +
src/protocol/child.c | 48 +++++++++++++++++++++++++++++++
src/sample/pgpool.conf.sample-logical | 2 ++
src/sample/pgpool.conf.sample-raw | 2 ++
src/sample/pgpool.conf.sample-replication | 2 ++
src/sample/pgpool.conf.sample-slony | 2 ++
src/sample/pgpool.conf.sample-stream | 2 ++
src/utils/pool_process_reporting.c | 5 ++++
11 files changed, 115 insertions(+)
diff --git a/doc.ja/src/sgml/connection-pooling.sgml b/doc.ja/src/sgml/connection-pooling.sgml
index ed20e7f..2893d24 100644
--- a/doc.ja/src/sgml/connection-pooling.sgml
+++ b/doc.ja/src/sgml/connection-pooling.sgml
@@ -1210,6 +1210,31 @@
</listitem>
</varlistentry>
+ <varlistentry id="guc-log-disconnections" xreflabel="log_disconnections">
+ <term><varname>log_disconnections</varname> (<type>boolean</type>)
+ <indexterm>
+ <!--
+ <primary><varname>log_disconnections</varname> configuration parameter</primary>
+ -->
+ <primary><varname>log_disconnections</varname> 設定パラメータ</primary>
+ </indexterm>
+ </term>
+ <listitem>
+ <para>
+ <!--
+ Setting to on, prints all client connection terminations to the log.
+ -->
+ onに設定されている場合、全てのクライアント接続終了をログへ出力します。
+ </para>
+ <para>
+ <!--
+ This parameter can be changed by reloading the <productname>Pgpool-II</> configurations.
+ -->
+ このパラメータは<productname>Pgpool-II</>の設定を再読み込みすることで変更可能です。
+ </para>
+ </listitem>
+ </varlistentry>
+
<varlistentry id="guc-log-error-verbosity" xreflabel="log_error_verbosity">
<term><varname>log_error_verbosity</varname> (<type>enum</type>)
<indexterm>
diff --git a/doc/src/sgml/connection-pooling.sgml b/doc/src/sgml/connection-pooling.sgml
index 48ca8dc..ccc99cf 100644
--- a/doc/src/sgml/connection-pooling.sgml
+++ b/doc/src/sgml/connection-pooling.sgml
@@ -780,6 +780,22 @@
</listitem>
</varlistentry>
+ <varlistentry id="guc-log-disconnections" xreflabel="log_disconnections">
+ <term><varname>log_disconnections</varname> (<type>boolean</type>)
+ <indexterm>
+ <primary><varname>log_disconnections</varname> configuration parameter</primary>
+ </indexterm>
+ </term>
+ <listitem>
+ <para>
+ Setting to on, prints all client connection terminations to the log.
+ </para>
+ <para>
+ This parameter can be changed by reloading the <productname>Pgpool-II</> configurations.
+ </para>
+ </listitem>
+ </varlistentry>
+
<varlistentry id="guc-log-error-verbosity" xreflabel="log_error_verbosity">
<term><varname>log_error_verbosity</varname> (<type>enum</type>)
<indexterm>
diff --git a/src/config/pool_config_variables.c b/src/config/pool_config_variables.c
index 8af4ea4..9760436 100644
--- a/src/config/pool_config_variables.c
+++ b/src/config/pool_config_variables.c
@@ -431,6 +431,16 @@ static struct config_bool ConfigureNamesBool[] =
},
{
+ {"log_disconnections", CFGCXT_RELOAD, LOGING_CONFIG,
+ "Logs end of a session.",
+ CONFIG_VAR_TYPE_BOOL, false, 0
+ },
+ &g_pool_config.log_disconnections,
+ false,
+ NULL, NULL, NULL
+ },
+
+ {
{"log_hostname", CFGCXT_RELOAD, LOGING_CONFIG,
"Logs the host name in the connection logs.",
CONFIG_VAR_TYPE_BOOL, false, 0
diff --git a/src/include/pool_config.h b/src/include/pool_config.h
index 524971b..156d9d9 100644
--- a/src/include/pool_config.h
+++ b/src/include/pool_config.h
@@ -243,6 +243,7 @@ typedef struct
char *pid_file_name; /* pid file name */
bool replication_mode; /* replication mode */
bool log_connections; /* logs incoming connections */
+ bool log_disconnections; /* logs closing connections */
bool log_hostname; /* resolve hostname */
bool enable_pool_hba; /* enables pool_hba.conf file
* authentication */
diff --git a/src/protocol/child.c b/src/protocol/child.c
index a064a59..0a9c795 100644
--- a/src/protocol/child.c
+++ b/src/protocol/child.c
@@ -56,6 +56,7 @@
#include "utils/pool_stream.h"
#include "utils/elog.h"
#include "utils/ps_status.h"
+#include "utils/timestamp.h"
#include "context/pool_process_context.h"
#include "context/pool_session_context.h"
@@ -90,6 +91,7 @@ static void validate_backend_connectivity(int front_end_fd);
static POOL_CONNECTION * get_connection(int front_end_fd, SockAddr *saddr);
static POOL_CONNECTION_POOL * get_backend_connection(POOL_CONNECTION * frontend);
static StartupPacket *StartupPacketCopy(StartupPacket *sp);
+static void log_disconnections(char *database, char *username);
static void print_process_status(char *remote_host, char *remote_port);
static bool backend_cleanup(POOL_CONNECTION * volatile *frontend, POOL_CONNECTION_POOL * volatile backend, bool frontend_invalid);
@@ -129,6 +131,8 @@ char remote_host[NI_MAXHOST]; /* client host */
char remote_port[NI_MAXSERV]; /* client port */
POOL_CONNECTION *volatile child_frontend = NULL;
+struct timeval startTime;
+
#ifdef DEBUG
bool stop_now = false;
#endif
@@ -254,6 +258,8 @@ do_child(int *fds)
{
accepted = 0;
connection_count_down();
+ if (pool_config->log_disconnections)
+ log_disconnections(child_frontend->database, child_frontend->username);
}
backend_cleanup(&child_frontend, backend, frontend_invalid);
@@ -361,6 +367,7 @@ do_child(int *fds)
}
accepted = 1;
+ gettimeofday(&startTime, NULL);
check_config_reload();
validate_backend_connectivity(front_end_fd);
@@ -382,6 +389,8 @@ do_child(int *fds)
backend = get_backend_connection(child_frontend);
if (!backend)
{
+ if (pool_config->log_disconnections)
+ log_disconnections(child_frontend->database, child_frontend->username);
pool_close(child_frontend);
child_frontend = NULL;
continue;
@@ -443,6 +452,8 @@ do_child(int *fds)
accepted = 0;
connection_count_down();
+ if (pool_config->log_disconnections)
+ log_disconnections(sp->database, sp->user);
timeout.tv_sec = pool_config->child_life_time;
timeout.tv_usec = 0;
@@ -1254,7 +1265,16 @@ child_will_go_down(int code, Datum arg)
/* count down global connection counter */
if (accepted)
+ {
connection_count_down();
+ if (pool_config->log_disconnections)
+ {
+ if (child_frontend)
+ log_disconnections(child_frontend->database, child_frontend->username);
+ else
+ log_disconnections("","");
+ }
+ }
if ((pool_config->memory_cache_enabled || pool_config->enable_shared_relcache)
&& !pool_is_shmem_cache())
@@ -1949,6 +1969,34 @@ retry_startup:
}
static void
+log_disconnections(char *database, char *username)
+{
+ struct timeval endTime;
+ long diff;
+ long secs;
+ int msecs,
+ hours,
+ minutes,
+ seconds;
+
+ gettimeofday(&endTime, NULL);
+ diff = (long) ((endTime.tv_sec - startTime.tv_sec) * 1000000 + (endTime.tv_usec - startTime.tv_usec));
+
+ msecs = (int) (diff % 1000000) / 1000;
+ secs = (long) (diff / 1000000);
+ hours = secs / 3600;
+ secs %= 3600;
+ minutes = secs / 60;
+ seconds = secs % 60;
+
+ ereport(LOG,
+ (errmsg("frontend disconnection: session time: %d:%02d:%02d.%03d "
+ "user=%s database=%s host=%s%s%s",
+ hours, minutes, seconds, msecs,
+ username, database, remote_host, remote_port[0] ? " port=" : "", remote_port)));
+}
+
+static void
print_process_status(char *remote_host, char *remote_port)
{
if (remote_port[0] == '\0')
diff --git a/src/sample/pgpool.conf.sample-logical b/src/sample/pgpool.conf.sample-logical
index a81fdb0..8aa9b90 100644
--- a/src/sample/pgpool.conf.sample-logical
+++ b/src/sample/pgpool.conf.sample-logical
@@ -196,6 +196,8 @@ log_line_prefix = '%t: pid %p: ' # printf-style string to output at beginning
log_connections = off
# Log connections
+log_disconnections = off
+ # Log disconnections
log_hostname = off
# Hostname will be shown in ps status
# and in logs if connections are logged
diff --git a/src/sample/pgpool.conf.sample-raw b/src/sample/pgpool.conf.sample-raw
index 023984f..2141d5c 100644
--- a/src/sample/pgpool.conf.sample-raw
+++ b/src/sample/pgpool.conf.sample-raw
@@ -197,6 +197,8 @@ log_line_prefix = '%t: pid %p: ' # printf-style string to output at beginning
log_connections = off
# Log connections
+log_disconnections = off
+ # Log disconnections
log_hostname = off
# Hostname will be shown in ps status
# and in logs if connections are logged
diff --git a/src/sample/pgpool.conf.sample-replication b/src/sample/pgpool.conf.sample-replication
index 7338f92..41b5728 100644
--- a/src/sample/pgpool.conf.sample-replication
+++ b/src/sample/pgpool.conf.sample-replication
@@ -192,6 +192,8 @@ log_line_prefix = '%t: pid %p: ' # printf-style string to output at beginning
log_connections = off
# Log connections
+log_disconnections = off
+ # Log disconnections
log_hostname = off
# Hostname will be shown in ps status
# and in logs if connections are logged
diff --git a/src/sample/pgpool.conf.sample-slony b/src/sample/pgpool.conf.sample-slony
index f1bef59..071ba7b 100644
--- a/src/sample/pgpool.conf.sample-slony
+++ b/src/sample/pgpool.conf.sample-slony
@@ -193,6 +193,8 @@ log_line_prefix = '%t: pid %p: ' # printf-style string to output at beginning
log_connections = off
# Log connections
+log_disconnections = off
+ # Log disconnections
log_hostname = off
# Hostname will be shown in ps status
# and in logs if connections are logged
diff --git a/src/sample/pgpool.conf.sample-stream b/src/sample/pgpool.conf.sample-stream
index 921fa6c..1529b48 100644
--- a/src/sample/pgpool.conf.sample-stream
+++ b/src/sample/pgpool.conf.sample-stream
@@ -197,6 +197,8 @@ log_line_prefix = '%t: pid %p: ' # printf-style string to output at beginning
log_connections = off
# Log connections
+log_disconnections = off
+ # Log disconnections
log_hostname = off
# Hostname will be shown in ps status
# and in logs if connections are logged
diff --git a/src/utils/pool_process_reporting.c b/src/utils/pool_process_reporting.c
index db5a608..9d6bca1 100644
--- a/src/utils/pool_process_reporting.c
+++ b/src/utils/pool_process_reporting.c
@@ -370,6 +370,11 @@ get_config(int *nrows)
StrNCpy(status[i].desc, "if true, print incoming connections to the log", POOLCONFIG_MAXDESCLEN);
i++;
+ StrNCpy(status[i].name, "log_disconnections", POOLCONFIG_MAXNAMELEN);
+ snprintf(status[i].value, POOLCONFIG_MAXVALLEN, "%d", pool_config->log_disconnections);
+ StrNCpy(status[i].desc, "if true, print closing connections to the log", POOLCONFIG_MAXDESCLEN);
+ i++;
+
StrNCpy(status[i].name, "log_hostname", POOLCONFIG_MAXNAMELEN);
snprintf(status[i].value, POOLCONFIG_MAXVALLEN, "%d", pool_config->log_hostname);
StrNCpy(status[i].desc, "if true, resolve hostname for ps and log print", POOLCONFIG_MAXDESCLEN);
More information about the pgpool-hackers
mailing list