前言
目前Push小组推送文章时使用的Storm、Hadoop和HBase等基础设施都是由其小组自己维护,连续两周周末都出现了实时计算集群崩溃的情况,个别机器分配到Storm Worker后会出现无法连接其他机器的提示。考虑到由于计算资源紧张,其Storm集群由A和B两个DC服务器构成,而且Push小组的集群中部署有Mesos/Marathon/Docker/HDFS/HBase等众多组件,问题查起来比较费劲,为此首先联系了公司运维帮忙查看两个机房之间网络和带宽情况,得到的反馈是没有问题,但是某一台机器TIME_WAIT居然可以到21万。
顺藤摸瓜
除了上述信息外,运维还透露了一下TIME_WAIT较多的机器ip和端口为10.12.6.6并且端口为50010,除了Storm日志中呈现的其他服务器无法连接该台服务器外,隐约记得Push组同学说起该IP上部署有DataNode且当天掉线了一次(没有保留好原始日志,暂时不呈现),于是登录到服务器上面进行问题确认。首先检查磁盘,内存,负载等常见指标:
[mesos@10.12.6.6 ~]$ df -hT 文件系统 类型 容量 已用 可用 已用% 挂载点 /dev/sda2 xfs 275G 23G 252G 9% / devtmpfs devtmpfs 63G 0 63G 0% /dev tmpfs tmpfs 63G 8.0K 63G 1% /dev/shm tmpfs tmpfs 63G 4.0G 59G 7% /run tmpfs tmpfs 63G 0 63G 0% /sys/fs/cgroup /dev/sdj1 xfs 745G 6.4G 739G 1% /ssd9 /dev/sdd1 xfs 745G 9.5G 736G 2% /ssd3 /dev/sdi1 xfs 745G 11G 735G 2% /ssd8 /dev/sdl1 xfs 745G 8.0G 737G 2% /ssd11 /dev/sdm1 xfs 745G 8.7G 737G 2% /ssd12 /dev/sdc1 xfs 745G 8.9G 736G 2% /ssd2 /dev/sdb1 xfs 745G 9.3G 736G 2% /ssd1 /dev/sdk1 xfs 745G 10G 735G 2% /ssd10 /dev/sdh1 xfs 745G 11G 735G 2% /ssd7 /dev/sde1 xfs 745G 14G 732G 2% /ssd4 /dev/sdf1 xfs 745G 11G 735G 2% /ssd5 /dev/sdg1 xfs 745G 11G 734G 2% /ssd6 /dev/sda1 xfs 797M 165M 632M 21% /boot tmpfs tmpfs 13G 0 13G 0% /run/user/0 cm_processes tmpfs 63G 76M 63G 1% /run/cloudera-scm-agent/process tmpfs tmpfs 13G 0 13G 0% /run/user/1000 tmpfs tmpfs 13G 0 13G 0% /run/user/10261 tmpfs tmpfs 13G 0 13G 0% /run/user/1001
并且对组网机器抽样进行ping测试然而没有发现明显异常,由于采用Mesos+Docker部署的Storm计算集群,因此决定翻翻日志看是否可以发现有价值的线索:
[mesos@10.12.6.6 ~]$ sudo tailf /var/log/messages Mar 23 20:46:41 10.12.6.6 systemd: Starting user-1001.slice. Mar 23 20:46:41 10.12.6.6 systemd-logind: New session 315531 of user mesos. Mar 23 20:46:41 10.12.6.6 systemd: Started Session 315531 of user mesos. Mar 23 20:46:41 10.12.6.6 systemd: Starting Session 315531 of user mesos. Mar 23 20:46:41 10.12.6.6 kernel: XFS (sdj1): xfs_log_force: error -5 returned. Mar 23 20:46:46 10.12.6.6 docker: time="2019-03-23T20:46:46.678336194+08:00" level=info msg="GET /v1.20/containers/json" Mar 23 20:47:01 10.12.6.6 systemd: Started Session 315532 of user worker. Mar 23 20:47:01 10.12.6.6 systemd: Starting Session 315532 of user worker. Mar 23 20:47:04 10.12.6.6 smartd[1190]: Device: /dev/sdj [SAT], open() failed: No such device Mar 23 20:47:11 10.12.6.6 kernel: XFS (sdj1): xfs_log_force: error -5 returned. Mar 23 20:47:21 10.12.6.6 mesos-slave[14215]: I0323 20:47:21.962821 14267 slave.cpp:4374] Current disk usage 8.33%. Max allowed age: 5.717025255624850days Mar 23 20:47:42 10.12.6.6 kernel: XFS (sdj1): xfs_log_force: error -5 returned. Mar 23 20:48:01 10.12.6.6 systemd: Started Session 315533 of user worker. Mar 23 20:48:01 10.12.6.6 systemd: Starting Session 315533 of user worker. Mar 23 20:48:12 10.12.6.6 kernel: XFS (sdj1): xfs_log_force: error -5 returned. Mar 23 20:48:21 10.12.6.6 mesos-slave[14215]: I0323 20:48:21.963692 14243 slave.cpp:4374] Current disk usage 8.33%. Max allowed age: 5.717027301642546days Mar 23 20:48:42 10.12.6.6 kernel: XFS (sdj1): xfs_log_force: error -5 returned.
从日志中发现了标志性提示:kernel: XFS (sdj1): xfs_log_force: error -5 returned.看来是其中一块SSD-/dev/sdj1对应的是ssd9似乎是坏掉了,再次进行确认:
[mesos@10.12.6.6 ssd9]$ ls ls: 无法打开目录.: 输入/输出错误 [mesos@10.12.6.6 ssd9]$ cd /ssd10 [mesos@10.12.6.6 ssd10]$ ls dfs impala mapred yarn
至此基本可以确认问题所在,可能有的同学会想一块坏掉的SSD为什么会和网络挂上钩,这里请注意50010端口哦!为了恢复SSD并实现重新挂载进行如下尝试:
[mesos@10.12.6.6 ~]$ sudo lsof|grep ssd9 lsof: WARNING: can't stat() xfs file system /ssd9 Output information may be incomplete. bash 3877316 zhang cwd unknown /ssd9 (stat: Input/output error) [mesos@10.12.6.6 ~]$ sudo kill -9 3877316 [mesos@10.12.6.6 ~]$ sudo umount /ssd9 [mesos@10.12.6.6 ~]$ sudo mount -a [mesos@10.12.6.6 ssd9]$ ls dfs yarn
再次启动Strom任务发现Worker分配和网络连接恢复正常,并且此时TIME_WAIT数量大大减少,任务恢复正常并且开始消费堆积数据。
转载请注明:雪后西塘 » kernel: XFS (sdj1): xfs_log_force: error -5 returned