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

2021 年 7 月 15 日
笔记
Apache Doris

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

1.查看日志

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

但是由于这部分信息并不完整，只能大致的帮助定位到可能的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小技巧
 函数调用知识

Tags: Apache Doris