KnowForge/Apache Kyuubi 1.9.1 简体中文
监控

1. 监控 Kyuubi - 日志系统

师成师成· 更新于 2026-09-29· 阅读 31 分钟· 0 次阅读
登录后可跨设备保存划线和私人笔记登录

1. 监控 Kyuubi — 日志系统

自 v1.5.0 版本起，Kyuubi 使用 Apache Log4j2 进行日志记录；对于 v1.4.1 及更早版本，则使用 Apache Log4j。

总体而言，Kyuubi 架构中主要有三个组件会生成面向组件的日志，帮助你追踪针对 Kyuubi 的 SQL 工作负载的线索（breadcrumbs）。

  • Kyuubi Server 的日志
  • Kyuubi Engine 的日志
  • 操作日志

此外，用于生产的 Kyuubi 部署通常还依赖一些其他外部系统。例如，Kyuubi Server 和引擎都会使用 Apache ZooKeeper 进行服务发现。关于外部系统日志的说明不在本文范围内。

1.1. Kyuubi Server 的日志

Kyuubi Server 的日志向我们展示了服务器实例的活动，包括如何启动/停止、如何响应客户端请求等。

1.1.1. 配置服务端日志

基本配置

你可以通过在 $KYUUBI_HOME/conf 目录中添加一个 log4j2.xml 文件来进行配置。一种可行的起步方式是复制该目录下已有的 log4j2.xml.template 文件。

例如：

# cd $KYUUBI_HOME
cp conf/log4j2.xml.template conf/log4j2.xml

无论是否执行上述步骤，默认情况下服务器日志都会重定向到 $KYUUBI_HOME/logs 目录下名为 kyuubi-${env:USER}-org.apache.kyuubi.server.KyuubiServer-${env:HOSTNAME}.out 的文件中。

例如，从控制台输出中，你可以轻松找到启动 Kyuubi 服务器时日志的去向。

$ export SPARK_HOME=/Users/kentyao/Downloads/spark/spark-3.2.0-bin-hadoop3.2
$ cd ~/svn-kyuubi/v1.3.1-incubating-rc0/apache-kyuubi-1.3.1-incubating-bin
$ bin/kyuubi start
Starting Kyuubi Server from /Users/kentyao/svn-kyuubi/v1.3.1-incubating-rc0/apache-kyuubi-1.3.1-incubating-bin
Warn: Not find kyuubi environment file /Users/kentyao/svn-kyuubi/v1.3.1-incubating-rc0/apache-kyuubi-1.3.1-incubating-bin/conf/kyuubi-env.sh, using default ones...
JAVA_HOME: /Library/Java/JavaVirtualMachines/jdk1.8.0_251.jdk/Contents/Home
KYUUBI_HOME: /Users/kentyao/svn-kyuubi/v1.3.1-incubating-rc0/apache-kyuubi-1.3.1-incubating-bin
KYUUBI_CONF_DIR: /Users/kentyao/svn-kyuubi/v1.3.1-incubating-rc0/apache-kyuubi-1.3.1-incubating-bin/conf
KYUUBI_LOG_DIR: /Users/kentyao/svn-kyuubi/v1.3.1-incubating-rc0/apache-kyuubi-1.3.1-incubating-bin/logs
KYUUBI_PID_DIR: /Users/kentyao/svn-kyuubi/v1.3.1-incubating-rc0/apache-kyuubi-1.3.1-incubating-bin/pid
KYUUBI_WORK_DIR_ROOT: /Users/kentyao/svn-kyuubi/v1.3.1-incubating-rc0/apache-kyuubi-1.3.1-incubating-bin/work
SPARK_HOME: /Users/kentyao/Downloads/spark/spark-3.2.0-bin-hadoop3.2
SPARK_CONF_DIR: /Users/kentyao/Downloads/spark/spark-3.2.0-bin-hadoop3.2/conf
HADOOP_CONF_DIR:
YARN_CONF_DIR:
Starting org.apache.kyuubi.server.KyuubiServer, logging to /Users/kentyao/svn-kyuubi/v1.3.1-incubating-rc0/apache-kyuubi-1.3.1-incubating-bin/logs/kyuubi-kentyao-org.apache.kyuubi.server.KyuubiServer-hulk.local.out
Welcome to
  __  __                           __
 /\ \/\ \                         /\ \      __
 \ \ \/'/'  __  __  __  __  __  __\ \ \____/\_\
  \ \ , <  /\ \/\ \/\ \/\ \/\ \/\ \\ \ '__`\/\ \
   \ \ \\`\\ \ \_\ \ \ \_\ \ \ \_\ \\ \ \L\ \ \ \
    \ \_\ \_\/`____ \ \____/\ \____/ \ \_,__/\ \_\
     \/_/\/_/`/___/> \/___/  \/___/   \/___/  \/_/
                /\___/
                \/__/

KYUUBI_LOG_DIR

你可能还会注意到上面示例中有一个名为 KYUUBI_LOG_DIR 的环境变量。

KYUUBI_LOG_DIR 用于指定我们希望存放服务器日志文件的目录。

例如，下面的命令会将日志文件定位到 /Users/kentyao/tmp。

$ mkdir /Users/kentyao/tmp
$ KYUUBI_LOG_DIR=/Users/kentyao/tmp bin/kyuubi start
Starting org.apache.kyuubi.server.KyuubiServer, logging to /Users/kentyao/tmp/kyuubi-kentyao-org.apache.kyuubi.server.KyuubiServer-hulk.local.out

KYUUBI_MAX_LOG_FILES

KYUUBI_MAX_LOG_FILES 用于控制 Kyuubi 服务器重启后保留多少个日志文件。

自定义 Log4j2 配置

接管 $KYUUBI_HOME/conf/log4j2.xml 同样可以让我们按照自己的意愿自定义服务器日志。

例如，我们可以禁用控制台 appender 并启用文件 appender，如下所示：

<Configuration status="INFO">
  <Appenders>
    <File name="fa" fileName="log/dummy.log">
      <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} %p %c: %m%n%ex"/>
      <Filters>
        <RegexFilter regex=".*Thrift error occurred during processing of message.*" onMatch="DENY" onMismatch="NEUTRAL"/>
      </Filters>
    </File>
  </Appenders>
  <Loggers>
    <Root level="INFO">
      <AppenderRef ref="fa"/>
    </Root>
  </Loggers>
</Configuration>

随后所有日志都会输出到 log/dummy.log。

1.2. Spark SQL Engine 的日志

Spark SQL Engine 是 Kyuubi 引擎的一种，也是一个典型的 Spark 应用。因此，其日志主要包含 Spark Driver 的日志。同时，它还包含引擎各个服务的启停过程、如何响应来自 Kyuubi Server 的调用等信息。

一般情况下，当异常发生时，我们可以在引擎日志中找到更多的信息和线索。

1.2.1. 配置引擎日志

请参阅 Apache Spark 在线文档中的 Configuring Logging 获取相关说明。

1.2.2. 如何查找引擎日志

引擎日志的位置会根据部署模式和集群管理器的不同而有所不同。当使用 local 后端，或其他集群管理器（如 YARN）的 client 部署模式时，你可以在 $KYUUBI_WORK_DIR_ROOT/${session username}/kyuubi-spark-sql-engine.log.${num} 中找到完整的引擎日志。不同的会话用户有不同的文件夹，用于归集其所有在线和历史引擎日志。每个引擎都只会有一个引擎日志。当使用 cluster 部署模式时，本地的引擎日志只包含很少的信息，引擎日志的主要部分在远端的 Driver 侧，例如对于 YARN 集群，这些日志位于 ApplicationMaster 的日志中。

1.3. Flink SQL Engine 的日志

Flink SQL Engine 是 Kyuubi 引擎的一种，也是一个典型的 Flink 应用。因此，其日志主要包含 Flink JobManager 和 TaskManager 的日志。同时，它还包含引擎各个服务的启停过程、如何响应来自 Kyuubi Server 的调用等信息。

一般情况下，当异常发生时，我们可以在引擎日志中找到更多的信息和线索。

1.3.1. 配置引擎日志

请参阅 Apache Flink 在线文档中的 Configuring Logging 获取相关说明。

1.3.2. 如何查找引擎日志

引擎日志的位置会根据部署模式和集群管理器的不同而有所不同。当使用 local 后端，或其他集群管理器（如 YARN）的 client 部署模式时，你可以在 $KYUUBI_WORK_DIR_ROOT/${session username}/kyuubi-flink-sql-engine.log.${num} 中找到完整的引擎日志。不同的会话用户有不同的文件夹，用于归集其所有在线和历史引擎日志。每个引擎都只会有一个引擎日志。当使用 cluster 部署模式时，本地的引擎日志只包含很少的信息，引擎日志的主要部分在远端的 Driver 侧，例如对于 YARN 集群，这些日志位于 ApplicationMaster 的日志中。

1.4. 操作日志

操作日志会展示 SQL 查询是如何执行的，例如查询规划、执行以及统计报告等。

操作日志可以直观地向最终用户展示他们的查询在服务端/引擎端是如何执行的，包括一些流程性的信息，以及查询为什么缓慢或出错。

例如，作为最终用户，你使用 beeline 连接 Kyuubi 服务端并执行如下查询：

bin/beeline -u 'jdbc:hive2://10.242.189.214:2181/;serviceDiscoveryMode=zooKeeper;zooKeeperNamespace=kyuubi' -n kent -e 'select * from src;'

你既会得到最终结果，也会得到相应的操作日志，其中记录了该查询的完整执行过程。

0: jdbc:hive2://10.242.189.214:2181/> select * from src;
2021-10-27 17:00:19.399 INFO operation.ExecuteStatement: Processing kent's query[fb5f57d2-2b50-4a46-961b-3a5c6a2d2597]: INITIALIZED_STATE -> PENDING_STATE, statement: select * from src
2021-10-27 17:00:19.401 INFO operation.ExecuteStatement: Processing kent's query[fb5f57d2-2b50-4a46-961b-3a5c6a2d2597]: PENDING_STATE -> RUNNING_STATE, statement: select * from src
2021-10-27 17:00:19.400 INFO operation.ExecuteStatement: Processing kent's query[26e169a2-6c06-450a-b758-e577ac673d70]: INITIALIZED_STATE -> PENDING_STATE, statement: select * from src
2021-10-27 17:00:19.401 INFO operation.ExecuteStatement: Processing kent's query[26e169a2-6c06-450a-b758-e577ac673d70]: PENDING_STATE -> RUNNING_STATE, statement: select * from src
2021-10-27 17:00:19.402 INFO operation.ExecuteStatement:
           Spark application name: kyuubi_USER_kent_6d4b5e53-ddd2-420c-b04f-326fb2b17e18
                 application ID: local-1635318669122
                 application web UI: http://10.242.189.214:50250
                 master: local[*]
                 deploy mode: client
                 version: 3.2.0
           Start time: 2021-10-27T15:11:08.416
           User: kent
2021-10-27 17:00:19.408 INFO metastore.HiveMetaStore: 6: get_database: default
2021-10-27 17:00:19.408 INFO HiveMetaStore.audit: ugi=kent	ip=unknown-ip-addr	cmd=get_database: default
2021-10-27 17:00:19.424 WARN conf.HiveConf: HiveConf of name hive.internal.ss.authz.settings.applied.marker does not exist
2021-10-27 17:00:19.424 WARN conf.HiveConf: HiveConf of name hive.stats.jdbc.timeout does not exist
2021-10-27 17:00:19.424 WARN conf.HiveConf: HiveConf of name hive.stats.retries.wait does not exist
2021-10-27 17:00:19.424 INFO metastore.HiveMetaStore: 6: Opening raw store with implementation class:org.apache.hadoop.hive.metastore.ObjectStore
2021-10-27 17:00:19.425 INFO metastore.ObjectStore: ObjectStore, initialize called
2021-10-27 17:00:19.430 INFO metastore.MetaStoreDirectSql: Using direct SQL, underlying DB is DERBY
2021-10-27 17:00:19.431 INFO metastore.ObjectStore: Initialized ObjectStore
2021-10-27 17:00:19.434 INFO metastore.HiveMetaStore: 6: get_table : db=default tbl=src
2021-10-27 17:00:19.434 INFO HiveMetaStore.audit: ugi=kent	ip=unknown-ip-addr	cmd=get_table : db=default tbl=src
2021-10-27 17:00:19.449 INFO metastore.HiveMetaStore: 6: get_table : db=default tbl=src
2021-10-27 17:00:19.450 INFO HiveMetaStore.audit: ugi=kent	ip=unknown-ip-addr	cmd=get_table : db=default tbl=src
2021-10-27 17:00:19.510 INFO operation.ExecuteStatement: Processing kent's query[26e169a2-6c06-450a-b758-e577ac673d70]: RUNNING_STATE -> RUNNING_STATE, statement: select * from src
2021-10-27 17:00:19.544 INFO memory.MemoryStore: Block broadcast_5 stored as values in memory (estimated size 343.6 KiB, free 408.6 MiB)
2021-10-27 17:00:19.558 INFO memory.MemoryStore: Block broadcast_5_piece0 stored as bytes in memory (estimated size 33.5 KiB, free 408.5 MiB)
2021-10-27 17:00:19.559 INFO spark.SparkContext: Created broadcast 5 from
2021-10-27 17:00:19.600 INFO mapred.FileInputFormat: Total input files to process : 1
2021-10-27 17:00:19.627 INFO spark.SparkContext: Starting job: collect at ExecuteStatement.scala:97
2021-10-27 17:00:19.629 INFO kyuubi.SQLOperationListener: Query [26e169a2-6c06-450a-b758-e577ac673d70]: Job 5 started with 1 stages, 1 active jobs running
2021-10-27 17:00:19.631 INFO kyuubi.SQLOperationListener: Query [26e169a2-6c06-450a-b758-e577ac673d70]: Stage 5 started with 1 tasks, 1 active stages running
2021-10-27 17:00:19.713 INFO kyuubi.SQLOperationListener: Finished stage: Stage(5, 0); Name: 'collect at ExecuteStatement.scala:97'; Status: succeeded; numTasks: 1; Took: 83 msec
2021-10-27 17:00:19.713 INFO scheduler.DAGScheduler: Job 5 finished: collect at ExecuteStatement.scala:97, took 0.085454 s
2021-10-27 17:00:19.713 INFO scheduler.StatsReportListener: task runtime:(count: 1, mean: 78.000000, stdev: 0.000000, max: 78.000000, min: 78.000000)
2021-10-27 17:00:19.713 INFO scheduler.StatsReportListener: 	0%	5%	10%	25%	50%	75%	90%	95%	100%
2021-10-27 17:00:19.713 INFO scheduler.StatsReportListener: 	78.0 ms	78.0 ms	78.0 ms	78.0 ms	78.0 ms	78.0 ms	78.0 ms	78.0 ms	78.0 ms
2021-10-27 17:00:19.714 INFO scheduler.StatsReportListener: shuffle bytes written:(count: 1, mean: 0.000000, stdev: 0.000000, max: 0.000000, min: 0.000000)
2021-10-27 17:00:19.714 INFO scheduler.StatsReportListener: 	0%	5%	10%	25%	50%	75%	90%	95%	100%
2021-10-27 17:00:19.714 INFO scheduler.StatsReportListener: 	0.0 B	0.0 B	0.0 B	0.0 B	0.0 B	0.0 B	0.0 B	0.0 B	0.0 B
2021-10-27 17:00:19.714 INFO scheduler.StatsReportListener: fetch wait time:(count: 1, mean: 0.000000, stdev: 0.000000, max: 0.000000, min: 0.000000)
2021-10-27 17:00:19.714 INFO scheduler.StatsReportListener: 	0%	5%	10%	25%	50%	75%	90%	95%	100%
2021-10-27 17:00:19.714 INFO scheduler.StatsReportListener: 	0.0 ms	0.0 ms	0.0 ms	0.0 ms	0.0 ms	0.0 ms	0.0 ms	0.0 ms	0.0 ms
2021-10-27 17:00:19.715 INFO scheduler.StatsReportListener: remote bytes read:(count: 1, mean: 0.000000, stdev: 0.000000, max: 0.000000, min: 0.000000)
2021-10-27 17:00:19.715 INFO scheduler.StatsReportListener: 	0%	5%	10%	25%	50%	75%	90%	95%	100%
2021-10-27 17:00:19.715 INFO scheduler.StatsReportListener: 	0.0 B	0.0 B	0.0 B	0.0 B	0.0 B	0.0 B	0.0 B	0.0 B	0.0 B
2021-10-27 17:00:19.715 INFO scheduler.StatsReportListener: task result size:(count: 1, mean: 1471.000000, stdev: 0.000000, max: 1471.000000, min: 1471.000000)
2021-10-27 17:00:19.715 INFO scheduler.StatsReportListener: 	0%	5%	10%	25%	50%	75%	90%	95%	100%
2021-10-27 17:00:19.715 INFO scheduler.StatsReportListener: 	1471.0 B	1471.0 B	1471.0 B	1471.0 B	1471.0 B	1471.0 B	1471.0 B	1471.0 B	1471.0 B
2021-10-27 17:00:19.717 INFO scheduler.StatsReportListener: executor (non-fetch) time pct: (count: 1, mean: 61.538462, stdev: 0.000000, max: 61.538462, min: 61.538462)
2021-10-27 17:00:19.717 INFO scheduler.StatsReportListener: 	0%	5%	10%	25%	50%	75%	90%	95%	100%
2021-10-27 17:00:19.717 INFO scheduler.StatsReportListener: 	62 %	62 %	62 %	62 %	62 %	62 %	62 %	62 %	62 %
2021-10-27 17:00:19.718 INFO scheduler.StatsReportListener: fetch wait time pct: (count: 1, mean: 0.000000, stdev: 0.000000, max: 0.000000, min: 0.000000)
2021-10-27 17:00:19.718 INFO scheduler.StatsReportListener: 	0%	5%	10%	25%	50%	75%	90%	95%	100%
2021-10-27 17:00:19.718 INFO scheduler.StatsReportListener: 	 0 %	 0 %	 0 %	 0 %	 0 %	 0 %	 0 %	 0 %	 0 %
2021-10-27 17:00:19.718 INFO scheduler.StatsReportListener: other time pct: (count: 1, mean: 38.461538, stdev: 0.000000, max: 38.461538, min: 38.461538)
2021-10-27 17:00:19.718 INFO scheduler.StatsReportListener: 	0%	5%	10%	25%	50%	75%	90%	95%	100%
2021-10-27 17:00:19.718 INFO scheduler.StatsReportListener: 	38 %	38 %	38 %	38 %	38 %	38 %	38 %	38 %	38 %
2021-10-27 17:00:19.719 INFO kyuubi.SQLOperationListener: Query [26e169a2-6c06-450a-b758-e577ac673d70]: Job 5 succeeded, 0 active jobs running
2021-10-27 17:00:19.728 INFO codegen.CodeGenerator: Code generated in 12.277091 ms
2021-10-27 17:00:19.729 INFO operation.ExecuteStatement: Processing kent's query[26e169a2-6c06-450a-b758-e577ac673d70]: RUNNING_STATE -> FINISHED_STATE, statement: select * from src, time taken: 0.328 seconds
2021-10-27 17:00:19.731 INFO operation.ExecuteStatement: Query[fb5f57d2-2b50-4a46-961b-3a5c6a2d2597] in FINISHED_STATE
2021-10-27 17:00:19.731 INFO operation.ExecuteStatement: Processing kent's query[fb5f57d2-2b50-4a46-961b-3a5c6a2d2597]: RUNNING_STATE -> FINISHED_STATE, statement: select * from src, time taken: 0.33 seconds
+-------------------------------------------------+--------------------+
|                    version()                    | DATE '2021-10-27'  |
+-------------------------------------------------+--------------------+
| 3.2.0 5d45a415f3a29898d92380380cfd82bfc7f579ea  | 2021-10-27         |
+-------------------------------------------------+--------------------+
1 row selected (0.341 seconds)

1.5. 延伸阅读

评论

登录后参与评论

正在加载评论…