SparkThriftServer内存泄漏排查

STS(SparkThrfitServer)版本

  • spark-3.2.1-bin-hadoop3.2

问题表现

  • Spark UI 经常无响应
  • STS 经常挂掉

问题分析

获取heap.hprof和gc.log

spark.driver.extraJavaOptions -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/home/spark/hbi/logs/ -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintTenuringDistribution -XX:+PrintHeapAtGC -XX:+PrintReferenceGC -XX:+PrintGCApplicationStoppedTime -Xloggc:/home/spark/hbi/logs/gc-%t.log

堆对象分析

  • 工具:jprofiler

大对象

heap.hprof

Hashtable引用链

Hashtable

ConcurrentHashMap引用链

ConcurrentHashmap

GC趋势

  • 工具:gcviewer
  • 黄色:新生代
  • 红色:老年代
  • 黑色:full gc
gc.log

结论

  1. 确定是内存泄漏了,而且内存大对象有两个
    a. Hashtable
    b. ConcurrentHashmap
  2. 两个大对象都被该对象引用
    a. SparkExecuteStatementOperation

STS架构

https://blog.51cto.com/u_15259710/4797692
https://www.jianshu.com/p/b719c6415411

Spark Thrift Server大量复用了HiveServer2的代码。

HiveServer2的架构主要是通过ThriftCLIService监听端口,然后获取请求后委托给CLIService处理。CLIService又一层层的委托,最终交给OperationManager处理。OperationManager会根据请求的类型创建一个Operation的具体实现处理。比如Hive中执行sql的Operation实现是SQLOperation。

Spark Thrift Server做的事情就是实现自己的CLIService——SparkSQLCLIService,接着也实现了SparkSQLSessionManager以及SparkSQLOperationManager。另外还实现了一个处理sql的Operation——SparkExecuteStatementOperation。这样,当Spark Thrift Server启动后,对于sql的执行就会最终交给SparkExecuteStatementOperation了。

Spark Thrift Server其实就重写了处理sql的逻辑,其他的请求处理就完全复用HiveServer2的代码了。比如建表、删除表、建view等操作,全部使用的是Hive的代码。

推测原因

大对象引用者

  • org.apache.spark.sql.hive.thriftserver.SparkExecuteStatementOperation
    • 注:下文中SparkExecuteStatementOperation统称为SESO

SESO引用者

  • org.apache.spark.sql.hive.thriftserver.SparkExecuteStatementOperation$$anon$1
    • 这是个什么东西?

SESO$$anon$1

  • 通过反编译,发现该类是SparkExecuteStatementOperation的内部类
    • 工具:jd-gui
  • $$anon$1通过$outer引用了SESO
import java.lang.invoke.SerializedLambda;
import java.util.concurrent.ScheduledExecutorService;
import org.apache.spark.sql.hive.thriftserver.SparkExecuteStatementOperation;
import org.apache.spark.sql.hive.thriftserver.SparkExecuteStatementOperation$;
import scala.Option;
import scala.util.control.NonFatal$;

public final class null implements Runnable {
  private final ScheduledExecutorService timeoutExecutor$1;
  
  public null(SparkExecuteStatementOperation $outer, ScheduledExecutorService timeoutExecutor$1) {}
  
  public void run() {
    try {
      this.$outer.timeoutCancel();
    } catch (Throwable throwable1) {
      Throwable throwable2 = throwable1;
      Option option = NonFatal$.MODULE$.unapply(throwable2);
    } finally {
      this.timeoutExecutor$1.shutdown();
    } 
  }
}

SESO内部类源码

  • 注意:timeout单位是TimeUnit.SECONDS
# 核心变量timeout
// If a timeout value `queryTimeout` is specified by users and it is smaller than
// a global timeout value, we use the user-specified value.
// This code follows the Hive timeout behaviour (See #29933 for details).
private val timeout = {
  val globalTimeout = sqlContext.conf.getConf(SQLConf.THRIFTSERVER_QUERY_TIMEOUT)
  if (globalTimeout > 0 && (queryTimeout <= 0 || globalTimeout < queryTimeout)) {
    globalTimeout
  } else {
    queryTimeout
  }
}

# 中间代码省略...

# 内部类创建逻辑
if (timeout > 0) {
  val timeoutExecutor = Executors.newSingleThreadScheduledExecutor()
  timeoutExecutor.schedule(new Runnable {
    override def run(): Unit = {
      try {
        timeoutCancel()
      } catch {
        case NonFatal(e) =>
          setOperationException(new HiveSQLException(e))
          logError(s"Error cancelling the query after timeout: $timeout seconds")
      } finally {
        timeoutExecutor.shutdown()
      }
    }
  }, timeout, TimeUnit.SECONDS)
}

原因推理

客户端

  • 请求超时时间queryTimeout > 0

服务端

  1. timeout默认等于客户端传过来的queryTimeout

  2. timeout大于0时,会创建单线程的线程池,提交延迟任务,延迟任务在timeout时间后开始执行,执行完成后会停止线程池
    a. 注意1:延迟任务作为SESO的内部类,会持有SESO的引用
    b. 注意2:timeout单位是seconds

3.问题原因:如果timeout时间很长,而且sql执行时间很短,如果短时间内有大量的查询,那么这些线程在timeout时间内一直持有延迟任务的引用,也就是间接持有SESO对象的引用,这就是内存溢出的原因

验证推理

跟踪timeout传入链

  • 找到入口方法
org.apache.hive.service.cli.CLIService#executeStatementAsync(org.apache.hive.service.cli.SessionHandle, java.lang.String, java.util.Map<java.lang.String,java.lang.String>, long)

监控命令

  • 工具:arthas
  • params[3]: timeout
# arthas watch 命令
watch org.apache.hive.service.cli.CLIService executeStatementAsync '{params}' 'params[3]>0' -x 2
watch method

提出疑问

  • 为什么 "SELECT 1" 的timeout是60000s(16.7h)

服务分析

哪个服务

  • 通过STS日志里查找sessionId,定位服务所在节点IP,从而定位到传入queryTimeout=60000的服务
  • 最终定位有问题的服务:hbi-query-engine
sts.log

原有连接池配置

# 连接池配置
engine.ds.hive.read.type = com.alibaba.druid.pool.DruidDataSource
# 单位是seconds,也就是16.7小时(Druid在用"SELECT 1"探活时使用该值)
engine.ds.hive.read.pool.queryTimeout=60000
# 单位是mills,也就是60秒(Druid没有使用该配置)
engine.ds.hive.read.pool.validationTimeout=60000
configDruid

改进后连接池配置

# 连接池配置
engine.ds.hive.read.type = com.zaxxer.hikari.HikariDataSource
# 单位是seconds,也就是5分钟
engine.ds.hive.read.pool.queryTimeout=300
# 单位是mills,也就是60秒(Hikari在用"SELECT 1"探活时使用该值)
engine.ds.hive.read.pool.validationTimeout=60000
configHikari

DruidDataSource探测流程

调用栈

stack

setQueryTimeout核心方法

setQueryTimeout

HikariDataSource探测流程

调用栈

stack

setQueryTimeout核心方法

setQueryTimeout

解决方案

  • 为了快速解决问题,目前采取方案1(或者方案2),方案3有时间再尝试

方案1

  1. 根据连接池不同,设置合理的queryTimeout、validationTimeout
    a. 注意1:queryTimeout的单位是seconds
    b. 注意2:validationTimeout单位是mills

方案2

  1. 在sts端配置globalTimeout,也就是spark.sql.thriftServer.queryTimeout
    a. 注:如果globalTimeout小于queryTimeout,则以globalTimeout为准

方案3

  1. 源码修复STS
    a. 思路:即时释放查询资源(线程池:timeoutExecutor)
    b. 实现:timeoutExecutor作为SESO的字段,并在SESO对象close时,调用timeoutExecutor.shutdown()

优化效果

全堆大小

Heap After GC

年轻代大小

Young Gen

老年代大小

Old Gen

工具列表

  1. jprofiler: 分析堆内存
  2. gcviewer: 分析垃圾回收
  3. gceasy: 分析垃圾回收 在线分析入口
  4. arthas: 分析方法调用
  5. jd-gui: 反编译

参考文档

  1. Hive内存溢出示例:https://www.jianshu.com/p/88626013b39f
  2. STS架构:https://www.jianshu.com/p/b719c6415411
  3. STS架构VS Kyuubi:https://blog.51cto.com/u_15259710/4797692
  4. Arthas watch:https://arthas.aliyun.com/doc/watch.html
最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 194,242评论 5 459
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 81,769评论 2 371
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 141,484评论 0 319
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 52,133评论 1 263
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 61,007评论 4 355
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 46,080评论 1 272
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 36,496评论 3 381
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 35,190评论 0 253
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 39,464评论 1 290
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 34,549评论 2 309
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 36,330评论 1 326
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 32,205评论 3 312
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 37,567评论 3 298
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 28,889评论 0 17
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 30,160评论 1 250
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 41,475评论 2 341
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 40,650评论 2 335

推荐阅读更多精彩内容