openGauss

开源数据库

openGauss社区官网

开源社区

openGauss数据库log_hostname参数分析

民生运维人2021-07-14openGauss数据库log_hostname参数分析

openGauss 数据库 log_hostname 参数分析

本文主要借助技术文档、源代码、实验三个方面的内容,分析 openGauss 数据库 log_hostname 参数的作用及影响范围。

技术文档

以下是官方文档关于 log_hostname 参数的几处描述:

  1. 开发者指南->GUC 参数说明->错误报告和日志->记录日志的内容:

    参数说明:选项关闭状态下,连接消息日志只显示正在连接主机的 IP 地址。打开此选项同时可以记录主机名。由于解析主机名可能需要一定的时间,可能影响数据库的性能。

    该参数属于 SIGHUP 类型参数

    取值范围:布尔型

    默认值:off

  2. 工具参考->客户端工具->gsql->常见问题处理->连接性能问题

    开启了 log_hostname,但是配置了错误的 DNS 导致的连接性能问题。

    连接上数据库,通过“show log_hostname”语句,检查数据库中是否开启了 log_hostname 参数。

    如果开启了相关参数,那么数据库内核会通过 DNS 反查客户端所在机器的主机名。这时如果数据库主节点配置了不正确的/不可达的 DNS 服务器,那么会导致数据库建立连接过程较慢。

  3. 开发者指南->应用程序开发教程->调试

    log_hostname 配置是否记录主机名 缺省时,连接日志只记录所连接主机的 IP 地址。打开这个选项会同时记录主机名。该参数同时影响 查看审计结果、GS_WLM_SESSION_HISTORY、PG_STAT_ACTIVITY 和 log_line_prefix 参数。

    log_connections/log_disconnections 配置是否在每次会话连接或结束时向服务器日志里打印一条信息。

  4. log_line_prefix 参数

    参数说明:控制每条日志信息的前缀格式。日志前缀类似于 printf 风格的字符串,在日志的每行开头输出。用以%为开头的“转义字符”代替表 1 中的状态信息。

    默认值:%m %c %d %p %a %x %n %e 表示在日志开头附加会话开始时间戳,会话 ID,数据库名,线程 ID,应用程序名,事务 ID,报错节点,SQLSTATE 错误码。

源代码

梳理源码之后认为,负责与用户交互的 postmaster 程序在数据库连接建立的时候进行用户认证、创建工作线程等工作,相关信息保存为当前会话/线程的全局变量(knl_session_context* u_sess;),包括按照 log_hostname 设置根据 IP 反向解析主机名。在连接/会话持续期间,应该不会重新获取连接信息。统计信息、WLM 等模块应该也是从这里获取相应信息。

涉及 log_hostname 参数的主要函数调用关系如下(另外还有一个线程池模式下的函数调用链条,并没有更多有用信息):

分别看一下各个函数:

  1. intGaussDbThreadMain(knl_thread_arg* arg) (位于 postmaster.cpp)

    用户响应主程序

  2. static void BackendInitialize(Port* port)

    函数注释:

    /*
    *BackendInitialize -- initialize an interactive (postmaster-child)
    
     *                         backendprocess, and collect the client's startup packet.
    ……
     */

    先调用 PreClientAuthorize 函数进行用户认证,再调用 ClientConnInitilize 函数。

    后边实验中 openGauss 的日志也确实打印了用户认证信息:

    [winchanged.qin.com] 2021-07-06 15:23:49.91160e40505.1068 postgres 140518193252096 dn_6001 0 dn_6001 00000 0 [BACKEND] LOG: connection authorized:user=jack database=postgres

  3. intClientConnInitilize(Port* port)

    函数中提到了 DNS 交互:DNS interactions。

    代码片段:

    /* Save session start time. */
        port->SessionStartTime =GetCurrentTimestamp();
        RemoteHostInitilize(port);
        /*
         * Ready to begin client interaction.  We will give up and exit(1) after a
         * time delay, so that a broken clientcan't hog a connection
         * indefinitely.  PreAuthDelayand any DNS interactions above don't count
         * against thetime limit.
         */
  4. static void RemoteHostInitilize(Port* port)

    函数作用:根据 IP 地址获取主机名,保存在当前会话中。

    代码片段:

    /*
         * Getthe remote host name and port for logging and status display.
         */
        remote_host[0] = '\0';
        remote_port[0] = '\0';
    if(pg_getnameinfo_all(&port->raddr.addr,
        if(u_sess->attr.attr_storage.Log_connections) {
            if (remote_port[0])
                ereport(LOG,(errmsg("connection received: host=%s port=%s", remote_host,remote_port)));
            else
                ereport(LOG,(errmsg("connection received: host=%s", remote_host)));
  5. int pg_getnameinfo_all()

  6. int getnameinfo()

    函数注释明确说明了反向解析 IP 地址的功能:Convert anipv4 address to a hostname。

    函数注释:

    /*
     * Convert an ipv4 address to a hostname.
     *
     * Bugs:  - Only supports NI_NUMERICHOST andNI_NUMERICSERV
     *            It will never resolv a hostname.
     *           - No IPv6 support.
     */

    代码片段:

     if (inet_net_ntop(AF_INET,
                       &((struct sockaddr_in*)sa)->sin_addr,
                       sa->sa_family == AF_INET ? 32 : 128,
                       node,
                       nodelen) == NULL) {
                    return EAI_MEMORY;
                }

    下边的参数初始化函数也提示:开启 log_hostname 可能会对性能产生不可忽视的影响。

    src\common\backend\utils\misc\guc.cpp:
    static void InitConfigureNamesBool()
           {{"log_hostname",
                PGC_SIGHUP,
                LOGGING_WHAT,
                gettext_noop("Logs the host name in the connection logs."),
                gettext_noop("By default, connection logs only show the IP address"
                             "of the connecting host. If you want them to show the host name you"
                             "can turn this on, but depending on your host nameresolution "
                              "setup it might impose anon-negligible performance penalty.")},
               &u_sess->attr.attr_common.log_hostname,

实验

在不同场景下通过 JDBC 客户端程序连接数据库,结合数据库连接耗时(单位为毫秒)、openGauss 日志、DNS 日志进行分析。

“不同场景”主要指 openGauss 的 log_hostname 参数、openGauss 服务器的 DNS 设置、DNS 服务设置的不同情况。

openGauss 服务器的 DNS 设置:

  • 不配置 DNS
  • 配置为正确的 DNS
  • 配置为错误的 DNS:DNS 服务器不存在、未开机

DNS 服务器设置:

  • unbound 服务正常
  • unboun 服务停止
  • 关机

实验环境:

类别

系统环境

地址

说明

openGauss服务器

CentOS7.6虚拟机

***.***.***.***

  

DNS服务器

CentOS7.6虚拟机

Unbound1.6.6(DNS)

***.***.***.***

DNS服务器与openGauss位于同一网段;只有一级DNS;

客户端测试程序

Windows+eclipse

openGauss JDBC2.0.0

***.***.***.***

  

客户端程序代码(官方示例代码):

public static void main(String[] args) {
    long startTime=System.currentTimeMillis();
    //创建数据库连接,连接地址:"jdbc:postgresql://***.***.***.***:26000/postgres"。
      Connection conn = GetConnection("jack", "*****@***");
        long endTime=System.currentTimeMillis();
        long time=endTime-startTime;
        System.out.println("连接耗时:"+ time);
      //批插数据。
      BatchInsertData(conn);
      BatchInsertData(conn);
      //关闭数据库连接。
      try {
        conn.close();
      } catch (SQLException e) {
        e.printStackTrace();
      }
  }

为方便查看日志,设置 openGauss 数据库的 GUC 参数:

  • log_line_prefix:[%h] %m %c %d %p %a %x %n %e

    日志行首信息,[%h]表示开启 log_hostname 的情况下,如果获取到了主机名则显示为主机名,否则显示为 IP

  • log_connections:on

    客户端连接时打印连接信息

  • log_disconnections:on

    客户端断开连接时打印会话持续时间

测试结果如下表:

序号

log_hostname

openGauss服务器

DNS服务器

10次连接耗时:

最短、最长(毫秒)

说明

1

off

不配置DNS

——

483-559

日志打印IP

2

on

配置DNS

服务正常

475-555

  

3

on

不配置DNS

——

500左右

  

4

on

配置DNS

服务正常,但是不包含客户端IP与主机的映射关系

500左右

日志打印IP,而不是主机名

5

on

配置DNS

服务关闭

476-525

日志打印IP,而不是主机名

6

on

错误的DNS服务器:19.19.19.19

——

10497-10566

关闭log_hostname之后新连接恢复正常

7

on

错误的DNS服务器:***.***.***.***(不存在,或者未开机)

——

首次:10513

后续九次:6534-6844

关闭log_hostname之后新连接恢复正常

8

on

配置DNS

客户端连接期间,停止DNS服务、修改IP和主机名映射、DNS指向不存在的IP

489-534

客户端连接期间,更改DNS服务不影响

9

off->on

先关闭log_hostname,客户端连接上之后再开启

服务正常

——

客户端连接期间,更改log_hostname不影响,还是只显示连接时的IP

根据实验结果得出以下结论:

  • 启用 log_hostname 并正常设置 DNS,数据库连接速度基本没有影响,耗时 500 毫秒左右;
  • 启用 log_hostname 但是不配置 DNS,数据库连接速度基本没有影响(与不启用 log_hostname 比)
  • 启用 log_hostname 并设置 DNS,但是 DNS 不包含客户端 IP 与主机的映射关系,数据库连接速度基本没有影响(与不启用 log_hostname 比)
  • 启用 log_hostname 并且 DNS 设置为不存在的 IP 地址,数据库连接速度骤降至 6-10 秒,因为要等 DNS 反向解析超时,关闭 log_hostname 之后新的数据库连接恢复正常;
  • 启用 log_hostname 并设置 DNS,DNS 服务器开机但是 unbound 服务未启动,数据库连接速度基本没有影响,此时由于获取不到主机名,日志只会打印 IP;
  • 启用 log_hostname,客户端连接持续期间,DNS 设置的变化不影响已建立的连接,包括停止 DNS 服务、修改 IP 和主机名映射、DNS 指向不存在的 IP,说明反向解析行为只会在连接的时候进行一次;
  • 启用 log_hostname 并设置 DNS,DNS 服务停止,连接时间不受影响,只是获取不到主机名;但是如果 DNS 服务器关机,连接速度极度恶化,与第四种情况一样了

提示:实验环境 DNS 服务器与 openGauss 服务器位于同一网段,只有一级 DNS,且映射关系很少,这可能是 DNS 反向解析未增加时间消耗的原因。

其他相关内容查询:

以下是查询到的与 log_hostname 相关的部分审计信息、统计信息:

  • select * from pg_query_audit('2021-07-0708:00:00','2021-07-07 10:00:00');

  • select time,type,result,username,database,client_conninfo,node_namefrom pg_query_audit('2021-07-0708:00:00','2021-07-07 10:00:00'); --倒数第二列显示了主机名

  • select datid,datname,pid,sessionid,usesysid,usename,application_name,client_addr,client_hostname,waiting,state from PG_STAT_ACTIVITY;--倒数第三列显示了主机名

主要证迹:

  • openGauss 日志,行首中括号为客户端的 IP 或者 hostname:

  • DNS 服务器 unbound 映射:

  • DNS 日志:

总结

启用 log_hostname,只会影响新的数据库连接,在 DNS 服务正常或 DNS 服务虽然未启动但所在机器正常运行的情况下,基本不影响连接耗时,但是在 DNS 服务器不可用(服务器关机、或者配置为不存在的服务器)的情况下,连接耗时明显增加。