Doris开发手记3:利用CoreDump文件快速定位Doris的查询问题

Apache Doris的BE部分是由C++编写,当出现一些内存越界,非法访问的问题时会导致BE进程的Crash。这部分的问题常常较难排查,同时也很难快速定位到对应的触发SQL,给使用者带来较大的困扰。所以下面会介绍通过Linux的CoreDump快速定位到问题SQL,并复现问题的方式。

1.查看日志

当BE进程Crash的时候,可以先查看be.out日志,确认是否存在stack trace的记录。当BE出现进程Crash的时,都会将运行时的堆栈打印到be.out文件中,一般如下图所示:

image.png

但是由于这部分信息并不完整,只能大致的帮助定位到可能的SQL查询。所以需要进一步的通过CoreDump来定位到触发BE Crash的查询。

2. 如何生成CoreDump

  • 查看生成CoreDump文件的开关是否开启,输入命令ulimit -a
core file size          (blocks, -c) 0
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) 513562
max locked memory       (kbytes, -l) 64
max memory size         (kbytes, -m) unlimited
open files                      (-n) 10240
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) 819200
real-time priority              (-r) 0
stack size              (kbytes, -s) 10240
cpu time               (seconds, -t) unlimited
max user processes              (-u) 513562
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited

第一行core file size为0,则不会生成CoreDump。使用 ulimit -c [kbytes]命令可以设置系统允许生成的CoreDump的文件大小。

ulimit -c 1024 #设置CoreDump文件大小为1024k

ulimit -c unlimited #不限制CoreDump文件大小

执行命令 ulimit -c unlimited,这样当BE进程Crash时就可以生成CoreDump文件。通过BE的start_be.sh脚本启动BE时,脚本会自动设置ulimit的参数。由于CoreDump文件较大,默认情况下不会开启CoreDump,所以这里需要修改BE的启动脚本。

chmod 755 ${DORIS_HOME}/lib/palo_be
echo "start time: "$(date) >> $LOG_DIR/be.out

#if [ ! -f /bin/limit3 ]; then
#    LIMIT=
#else
#    LIMIT="/bin/limit -c unlimited -n 65536"
#fi

ulimit -c unlimited -n 65536
if [ ${RUN_DAEMON} -eq 1 ]; then
    nohup $LIMIT ${DORIS_HOME}/lib/palo_be "$@" >> $LOG_DIR/be.out 2>&1 </dev/null &
else
    $LIMIT ${DORIS_HOME}/lib/palo_be "$@" >> $LOG_DIR/be.out 2>&1 </dev/null
fi

直接在启动BE进程之前手动通过ulimit -c unlimited -n 65536的方式开启CoreDump。

  • 指定生成CoreDump文件的路径

默认情况下,CoreDump生成的文件名为core,而且就在运行启动BE脚本目录下,新生成的CoreDump文件会覆盖旧的CoreDump文件。

而如果proc/sys/kernel/core_uses_pid内容为1,则CoreDump文件会以core.进程id的方式被生成。(这里建议通过系统管理员将该开关打开)。

如果在运行启动BE脚本目录下没有找到对应的CoreDump文件的话,可能是系统管理员修改了core_pattern

cat /proc/sys/kernel/core_pattern
/tmp/core_%t_%e_%p

这里显示CoreDump文件被core_pattern定义设置在了/tmp目录下,所以需要到对应的目录查找BE生成的CoreDump文件。

3.利用CoreDump定位问题Query

通过合理的配置之后,BE在Crash时就能正常生成CoreDump文件。利用GDB的打开CoreDump文件就能帮助我们取得对应的Query ID。

  • 使用GDB打开CoreDump文件
gdb be/lib/palo_be core.13610 

通常core文件会生成在BE进程的启动目录,但是如果额外配置过core-pattern,就得到对应的目录上找到对应的coredump文件,然后通过gdb be的binary coredump来打开它。

  • 通过查询栈索引到QueryID

打开之后,用bt命令展开堆栈,得到展开之后详细的堆栈信息

#0  0x00000000013957c6 in std::_Bit_reference::operator bool (this=<optimized out>) at /opt/rh/devtoolset-10/root/usr/include/c++/10/bits/stl_bvector.h:916
#1  std::_Bit_const_iterator::operator* (this=<optimized out>) at /opt/rh/devtoolset-10/root/usr/include/c++/10/bits/stl_bvector.h:348
#2  std::vector<bool, std::allocator<bool> >::operator[] (__n=<optimized out>, this=<optimized out>) at /opt/rh/devtoolset-10/root/usr/include/c++/10/bits/stl_bvector.h:918
#3  doris::RowDescriptor::tuple_is_nullable (this=0xc39f343f8, tuple_idx=-2073834344) at ../src/runtime/descriptors.cpp:357
#4  0x000000000113ae73 in doris::SlotRef::prepare(doris::RuntimeState*, doris::RowDescriptor const&, doris::ExprContext*) () at ../src/exprs/slot_ref.cpp:100
#5  0x0000000001124a33 in doris::ExprContext::prepare(doris::RuntimeState*, doris::RowDescriptor const&, std::shared_ptr<doris::MemTracker> const&) () at ../src/exprs/expr_context.cpp:61
#6  0x000000000111b29e in doris::Expr::prepare(std::vector<doris::ExprContext*, std::allocator<doris::ExprContext*> > const&, doris::RuntimeState*, doris::RowDescriptor const&, std::shared_ptr<doris::MemTracker> const&) () at /opt/rh/devtoolset-10/root/usr/include/c++/10/bits/stl_vector.h:1061
#7  0x0000000001ae4233 in doris::ResultSink::prepare_exprs(doris::RuntimeState*) () at ../src/runtime/result_sink.cpp:57
#8  0x0000000001ae4a07 in doris::ResultSink::prepare(doris::RuntimeState*) () at ../src/runtime/result_sink.cpp:69
#9  0x000000000146691b in doris::PlanFragmentExecutor::prepare(doris::TExecPlanFragmentParams const&, doris::QueryFragmentsCtx const*) ()
    at /var/local/thirdparty/installed/include/boost/smart_ptr/scoped_ptr.hpp:109
#10 0x00000000013e033e in doris::FragmentExecState::prepare (this=this@entry=0xc8fc6a00, params=...) at ../src/runtime/fragment_mgr.cpp:229
#11 0x00000000013e4217 in doris::FragmentMgr::exec_plan_fragment(doris::TExecPlanFragmentParams const&, std::function<void (doris::PlanFragmentExecutor*)>) () at ../src/runtime/fragment_mgr.cpp:609
#12 0x00000000013e5e5d in doris::FragmentMgr::exec_plan_fragment(doris::TExecPlanFragmentParams const&) () at /opt/rh/devtoolset-10/root/usr/include/c++/10/bits/std_function.h:87
#13 0x00000000014ab4e4 in doris::PInternalServiceImpl<doris::PBackendService>::_exec_plan_fragment (this=this@entry=0x8e80ef00, ser_request=...) at ../src/runtime/exec_env.h:117
#14 0x00000000014ab59f in doris::PInternalServiceImpl<doris::PBackendService>::exec_plan_fragment (this=0x8e80ef00, cntl_base=<optimized out>, request=<optimized out>, response=0x8b1aa7c00,
    done=0x7fc493fc0) at /var/local/thirdparty/installed/include/google/protobuf/arenastring.h:231
#15 0x0000000002086c97 in brpc::policy::ProcessHttpRequest(brpc::InputMessageBase*) () at ../src/brpc/policy/http_rpc_protocol.cpp:1484
#16 0x00000000020540b7 in brpc::ProcessInputMessage (void_arg=void_arg@entry=0x3fd337d50) at ../src/brpc/input_messenger.cpp:135
#17 0x0000000002054f7e in brpc::RunLastMessage::operator() (last_msg=0x3fd337d50, this=<synthetic pointer>) at ../src/brpc/input_messenger.cpp:141
#18 std::unique_ptr<brpc::InputMessageBase, brpc::RunLastMessage>::~unique_ptr (this=<synthetic pointer>, __in_chrg=<optimized out>) at /opt/rh/devtoolset-10/root/usr/include/c++/10/bits/unique_ptr.h:361
#19 brpc::InputMessenger::OnNewMessages(brpc::Socket*) () at /opt/rh/devtoolset-10/root/usr/include/c++/10/bits/unique_ptr.h:355
#20 0x00000000020fd52e in brpc::Socket::ProcessEvent(void*) () at ../src/brpc/socket.cpp:1017
#21 0x00000000021a5e6f in bthread::TaskGroup::task_runner(long) () at ../src/bthread/task_group.cpp:296
#22 0x0000000002197271 in bthread_make_fcontext () at /opt/rh/devtoolset-10/root/usr/include/c++/10/bits/stl_iterator.h:953
Backtrace stopped: Cannot access memory at address 0x7f644bcef000

doris::PlanFragmentExecutor的成员变量之中存储了对应的_query_id,也就是执行这个查询的全局唯一标识。我们可以看到,栈9上是doris::PlanFragmentExecutor的函数调用,所以通过f 9切换到栈9,并打印_query_id

(gdb) f 9
#9  0x000000000176d346 in doris::PlanFragmentExecutor::prepare (this=this@entry=0xcdf2cd8, request=..., fragments_ctx=<optimized out>)
    at /home/happen/mycode/baidu/bdg/doris/thirdparty-gcc10/installed/include/boost/smart_ptr/scoped_ptr.hpp:109
109     T * get() const BOOST_SP_NOEXCEPT
(gdb) p _query_id
$1 = {_vptr.TUniqueId = 0x3e41ed8 <vtable for doris::TUniqueId+16>, hi = -374422143996836436, lo = -6672731362362486359}

这里的query_id并不是我们真正需要的十六进制,所以还得继续通过GDB打印对应的十六进制的query_id。

(gdb) p /x -374422143996836436
$2 = 0xfacdc90b370745ac

到此已经定位到对应的query_id了,需要到FE的之中通过十六进制的query_id来查找对应的Query,这里的query_id, 不包括前面的0x。

通过FE的fe.audit.log搜索上文的facdc90b370745ac,由于FE对于查询失败的query有重试机制,所以这里定位到重试的query_id: 9427f07d3c964dc8-b6bc0e004f52508f来最终定位到触发问题的SQL为:select sum(cast(k9 as largeint)) from baseall

2021-07-11 18:46:32,098 [query] Query facdc90b370745ac-a365b22df8c691a9 1 times with new query id: 9427f07d3c964dc8-b6bc0e004f52508f
2021-07-11 18:46:32,100 [query] |Client=10.152.24.30:53143|User=root|Db=default_cluster:test|State=ERR|Time=257|ScanBytes=0|ScanRows=0|ReturnRows=0|StmtId=7|QueryId=9427f07d3c964dc8-b6bc0e004f52508f|IsQuery=true|feIp=10.152.24.30|Stmt=select sum(cast(k9 as largeint)) from baseall|CpuTimeMS=0

注意,由于可能存在多FE的情况,所以这里可能需要查询所有FE的fe.audit.log来搜索对应的query_id

到此,我们已经按图索骥的找到触发BE Crash的问题查询了。接下来就是尝试通过该查询来复现问题,并分析原因,尝试解决或规避问题查询。当然,如果希望社区能够提供帮助,可以将建表语句和脱敏过的数据提供给到社区的小伙伴们。

4.参考资料

Apache Doris源代码
100个GDB小技巧
函数调用知识

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

推荐阅读更多精彩内容