vmcore分析案例："kernel BUG at fs/buffer.c:1270"
centos 7 虚拟机内核 3.10.0-123.9.3.el7.x86_64
如果系统crash并且dump出了vmcore（vmcore是通过kdump这样的工具dump出内存），可以参考以下方法来排查vmcore
wget http://debuginfo.centos.org/7/x86_64/kernel-debuginfo-3.10.0-123.9.3.el7.x86_64.rpm
rpm2cpio kernel-debuginfo-3.10.0-123.9.3.el7.x86_64.rpm |cpio -idv ./usr/lib/debug/lib/modules/3.10.0-123.9.3.el7.x86_64/vmlinux
crash ./usr/lib/debug/lib/modules/3.10.0-123.9.3.el7.x86_64/vmlinux /vm/corefile/vm-1_corefile此时可以看到Kernel Panic的概要信息，指出导致Panic的BUG位于fs/buffer.c:1270
KERNEL: ./usr/lib/debug/lib/modules/3.10.0-123.9.3.el7.x86_64/vmlinux
DUMPFILE: vm-1_corefile
CPUS: 4 [OFFLINE: 3]
DATE: Fri Feb 24 08:48:45 2017
UPTIME: 154 days, 20:50:21
LOAD AVERAGE: 0.29, 0.26, 0.23
TASKS: 275
NODENAME: vm-1
RELEASE: 3.10.0-123.9.3.el7.x86_64
VERSION: #1 SMP Thu Nov 6 15:06:03 UTC 2014
MACHINE: x86_64 (2593 Mhz)
MEMORY: 4 GB
PANIC: "kernel BUG at fs/buffer.c:1270!"
PID: 28635
COMMAND: "php-fpm"
TASK: ffff880138e94440 [THREAD_INFO: ffff8800496fa000]
CPU: 3
STATE: (PANIC)CentOS 5的core文件分析时候，遇到报错
crash: cannot resolve: "xtime"，需要使用crash version 6.0.5以上版本（crash version 6.0.5 is available），通常使用CentOS 7自带的crash版本较好，或者从 crash官网 下载crash源代码在CentOS5编译安装。（参考Linux kdump）
首先检查vm crash时候系统日志，输入dmesg ，可以看到
系统日志排查
连续的
bio: create slab
kernel periodically logs 'create slab' messages 指出，这个create slab 并不是BUG，只是一个信息输出，表示the block layer started using incrementally larger allocations. bio-0 = 4k, bio-1 = 8k, bio-2 = 16k etc.. 数据块层开始使用递增的更大的分配，bio-0表示4k，bio-1表示8k，bio-2表示16k，依次类推。
[153039.317114] hrtimer: interrupt took 2016981 ns
参考 What does "hrtimer: interrupt" mean? 这个消息通常是因为非常高的CPU使用率的时候出现，表示CPU的一个中断事件。如果偶然看到则不用担心。但是如果经常看到hrtimer: interrupt消息则表示服务器资源不足，需要迁移到资源更多的服务器或者需要排查运行在服务器上的应用看是否有导致系统hang住的软件。
systemd-journald[342]: Vacuuming done, freed 0 bytes
参考 What do systemd “Vacuuming done, freed 0 bytes” messages mean?
vacuum 是
真空，吸尘的意思
journald vacuum size --vacuum-size=表示删除归档等日志文件直到日志使用的磁盘空间低于指定大小（可以使用"K","M","G","T"）
EXT4-fs (dm-2): mounted filesystem with ordered data mode. Opts: (null)
这个日志记录应该是正常的，只是表示挂载文件系统
[6732114.764622] TCP: TCP: Possible SYN flooding on port 11211. Sending cookies. Check SNMP counters.
参考 "kernel: Possible SYN flooding on port X. Sending cookies" is logged 这条日志是表示内核检测到SYN攻击。
[12718399.920299] device-mapper: ioctl: unable to remove open device docker-253:1-1053135-994bc83181568ed5a7f985b121535d0088ad8c2d5c80e43691a472590f204701-init
看来在OS内部使用了Docker
traps: php-fpm[27016] general protection ip:6abbe9 sp:7ffff953ee30 error:0 in php-fpm[400000+860000]
General protection fault(GPF)是Intel x86处理器的保护机制。如果处理器检测到一个protection violation（保护违反），就会停止执行代码并发送一个GPF中断。很多情况下姜导致操作系统从执行队列中删除故障的进程，通知用户，并继续执行其他进程。但是，如果操作系统没有捕获到general protection fault，例如，其他保护校验在操作系统从上一个GPF中断中返回之前又发生了一个protection violation，此时处理器就会触发double fault，就会停止操作系统。如果是另外一个failure（triple fault）发生（接连发生3次），则处理器停止工作并且响应一个reset操作。
php-fpm[26318]: segfault at 7f223d1df128 ip 000000000067a851 sp 00007ffff953ef20 error 4 in php-fpm[400000+860000]php-fpm segfault常见的错误有error 4和error 6上述系统日志显示
php-fpm多次触发GPF
导致php-fpm GPF的库文件是taeprobe.so (traps: php-fpm[28635] general protection ip:7f223396fc80 sp:7ffff953ec40 error:0 in taeprobe.so[7f2233965000+f000])，所以推测是TAE存在的BUG。
CPU: 3 PID: 28635 Comm: php-fpm Tainted: GF O-------------- 3.10.0-123.9.3.el7.x86_64 #1
这段Call Trace显示的调用函数和ext4文件系统写入缓存有关
kernel BUG at fs/buffer.c:1270
上述Kernel Panic出现在内核3.10.0-123.9.3.el7.x86_64代码fs/buffer.c:1270，这个BUG在Docker的Kernel Panic - Centos 7.2 3.10.0 - with devicemapper LVM thinpool ext4 #25504可以看到类似issue，原因和EXT4文件系统有关。
In looking at the changelog for the latest available 3.10 kernel on Centos 7.2, I don't see any fixes that appear related, so I'm hesitant to just roll out a kernel upgrade in hopes it fixes it. I've been unable to locate similar panics in my searching.
该BUG报告中提供的线索是通过更换文件系统到XFS来绕过这个BUG。
Last updated
Was this helpful?