coredump信息
(gdb) bt full
#0 0x000055c37fa62c00 in perf_evsel__parse_sample (evsel=0x55c381223b00, event=0x7f144843ab30, data=0x7ffcbbcf6540) at util/evsel.c:1939
type = <optimized out>
swapped = <optimized out>
array = <optimized out>
max_size = <optimized out>
endp = <optimized out>
sz = <optimized out>
u = <optimized out>
#1 0x000055c37fa5c9ef in perf_evlist__parse_sample (evlist=<optimized out>, event=event@entry=0x7f144843ab30, sample=sample@entry=0x7ffcbbcf6540) at util/evlist.c:1415
evsel = <optimized out>
#2 0x000055c37fa9f169 in perf_session__deliver_event (session=0x55c38122f0a0, event=0x7f144843ab30, tool=0x55c37fd4f120 <record>, file_offset=3980080) at util/session.c:1483
sample = {ip = 0, pid = 2693265664, tid = 349153765, time = 0, addr = 94298151645472, id = 4242048, stream_id = 94298173534368, period = 139725088729728, weight = 140723459417504,
transaction = 140723459418880, insn_cnt = 94298148829675, cyc_cnt = 0, cpu = 571808, raw_size = 0, data_src = 0, phys_addr = 0, flags = 0, insn_len = 0, cpumode = 0 '\000', misc = 0,
insn = '\000' <repeats 15 times>, raw_data = 0x0, callchain = 0x0, branch_stack = 0x0, user_regs = {abi = 0, mask = 0, regs = 0x0, cache_regs = {0 <repeats 64 times>}, cache_mask = 0},
intr_regs = {abi = 0, mask = 0, regs = 0x0, cache_regs = {0 <repeats 45 times>, 1499604004643535104, 0, 0, 0, 0, 1914, 264, 0, 0, 0, 1499604004643535104, 0, 0, 0, 0, 94298149818197,
1914, 0, 0}, cache_mask = 0}, user_stack = {offset = 0, size = 0, data = 0x0}, read = {time_enabled = 94298175016936, time_running = 24048125519245, {group = {nr = 140723459418768,
values = 0x55c37faa2dd6 <queue_event+86>}, one = {value = 140723459418768, id = 94298148842966}}}}
ret = <optimized out>
#3 0x000055c37faa307d in do_flush (show_progress=true, oe=0x55c381235bb0) at util/ordered-events.c:244
head = 0x55c381235bd8
tmp = 0x55c381392378
iter = 0x55c3813923a0
limit = 18446744073709551615
prog = {title = 0x55c37fbaa388 "Processing time ordered events...", curr = 0, next = 119, step = 119, total = 1914, size = false}
ret = <optimized out>
last_ts = 24048125519245
head = <optimized out>
tmp = <optimized out>
iter = <optimized out>
limit = <optimized out>
last_ts = <optimized out>
prog = <optimized out>
ret = <optimized out>
__mptr = <optimized out>
__mptr = <optimized out>
__u = <optimized out>
__mptr = <optimized out>
__mptr = <optimized out>
#4 __ordered_events__flush (oe=0x55c381235bb0, how=OE_FLUSH__FINAL, timestamp=timestamp@entry=0) at util/ordered-events.c:323
err = <optimized out>
show_progress = true
str = {0x55c37fb897fc "NONE", 0x55c37fb90f55 "FINAL", 0x55c37fb8e667 "ROUND", 0x55c37fb90f5b "HALF ", 0x55c37fb90f61 "TOP ", 0x55c37fb90f67 "TIME "}
#5 0x000055c37faa3849 in __ordered_events__flush (timestamp=<optimized out>, how=<optimized out>, oe=<optimized out>) at util/ordered-events.c:339
err = <optimized out>
show_progress = <optimized out>
str = {0x55c37fb897fc "NONE", 0x55c37fb90f55 "FINAL", 0x55c37fb8e667 "ROUND", 0x55c37fb90f5b "HALF ", 0x55c37fb90f61 "TOP ", 0x55c37fb90f67 "TIME "}
err = <optimized out>
show_progress = <optimized out>
first = <optimized out>
last = <optimized out>
head = <optimized out>
__mptr = <optimized out>
__warned = 0
__ret_warn_once = <optimized out>
__ret_warn_on = <optimized out>
#6 ordered_events__flush (how=<optimized out>, oe=<optimized out>) at util/ordered-events.c:341
coredump分析
从coredump的栈来看,perf执行流程是正常的,搜了下SIGBUS可能的原因如下:
1、文件映射访问异常
这是 SIGBUS 在用户态最为常见的场景,也最容易触发,通常来说根本原因都是进程 mmap 了一个文件后,另外的进程把这个文件截断了,导致 mmap 出来的某些内存页超出文件的实际大小,访问那些超出的内存页就会触发 SIGBUS,具体来说有以下几种场景:
1、进程 mmap 一个文件后,其它进程 truncate 该文件到更小。
2、动态库更新,直接 cp 覆盖。
3、可执行文件更新,直接 cp 覆盖。
系统读取磁盘文件通常是按页映射到内存,出于效率考虑常常使用 copy on write 机制,所以文件映射之后,如果对应的文件 page 不存在了(truncated),也不见得会马上出问题,只有到访问时才会出错,因此有一定滞后期。
2、访问不对齐的内存##
X86 平台上访问不对齐的内存时,默认不会有问题,但用户可以手动设置 EFLAGS 把 CPU 设置为不允许非对齐的内存访问,此时如果出现不对齐的内存访问,SIGBUS 就会抛出,具体例子参看【3】。
3、Stack fault exception
这种场景非常罕见,通常是 OS 或者内存硬件问题,从 intel 的开发者文件来看,这种异常属于 trap,并不是我们用户态常说的 exception,这种异常有三种起因【4】:
1、canonical address violation.
Canonical address 指的是 64 位模式下,地址的高 48 ~ 64 不是全部是 0 或 1 的地址。
如果通过栈指针 rbp 或 rsp 访问了非 canonical address 内核就会发 stack fault trap,示例代码如下:
要注意的是只有栈指针操作才会 SIGBUS,非栈指针引发的这类异常,只会抛 SIGSEG。
2、栈指针操作引用了超出栈大小的地址。
这类操作我还没法重现,只是文档说了可以触发。
3、栈操作引用了不存在的 stack segment。
这类操作通常是内核或编译器的 bug。
综上可知,stack fault 必然是与 rsp/rbp 这样的栈指针操作相关,通常用户态不大可能触发,如果不是 mmap 相关的异常,大多可能是内核或硬件问题(这里有些绝对),这类异常通常会导致内核在 /var/log/messages 下输出如下一条消息:
问题定位
从以上分析可知,大概率和mmap有关,怀疑代码中存在文件并发访问的问题,把问题代码写成小程序在系统上面循环跑测试:
while true; do ./perftest; echo "good";done
发现系统出现SIGBUS的coredump,继续跟踪perf进程:
发现perf是由于文件并发访问导致的SIGBUS。
参考:
https://www.cnblogs.com/catch/p/10973762.html
https://www.cnblogs.com/chenpingzhao/p/5563605.html