记一次Ceph故障处理

xuanhao

　　        ceph存储集群是建立在两台服务器上面，两台服务器各有4个OSD节点，上班的时候发现，两台服务器上其中一台服务器上4个OSD节点全部掉线，重启OSD节点后恢复正常。查看OSD节点日志后发现，整个故障过程如下：
　　

　　1. 单个OSD节点接收不到另外一台服务器节点上的所有OSD心跳信息，日志记录如下
2016-03-21 17:43:42.426051 7f716e0a7700 -1 osd.0 70 heartbeat_check: no reply from osd.5 since back 2016-03-21 17:43:22.233321 front 2016-03-21 17:43:41.335367 (cutoff 2016-03-21 17:43:22.426050)
2016-03-21 17:43:42.426061 7f716e0a7700 -1 osd.0 70 heartbeat_check: no reply from osd.6 since back 2016-03-21 17:43:22.233321 front 2016-03-21 17:43:41.335367 (cutoff 2016-03-21 17:43:22.426050)
2016-03-21 17:43:42.426072 7f716e0a7700 -1 osd.0 70 heartbeat_check: no reply from osd.7 since back 2016-03-21 17:43:22.233321 front 2016-03-21 17:43:41.335367 (cutoff 2016-03-21 17:43:22.426050)
2016-03-21 17:43:42.426075 7f716e0a7700 -1 osd.0 70 heartbeat_check: no reply from osd.8 since back 2016-03-21 17:43:22.233321 front 2016-03-21 17:43:41.335367 (cutoff 2016-03-21 17:43:22.426050)　　

　　2. 单个OSD节点接收不到相同服务器上其他节点的OSD心跳信息；
2016-03-21 17:43:53.427874 7f716e0a7700 -1 osd.0 74 heartbeat_check: no reply from osd.1 since back 2016-03-21 17:43:26.134353 front 2016-03-21 17:43:51.036748 (cutoff 2016-03-21 17:43:33.427873)
2016-03-21 17:43:53.427911 7f716e0a7700 -1 osd.0 74 heartbeat_check: no reply from osd.3 since back 2016-03-21 17:43:26.134353 front 2016-03-21 17:43:51.036748 (cutoff 2016-03-21 17:43:33.427873)
2016-03-21 17:44:07.937952 7f71410e4700 -1 osd.0 75 heartbeat_check: no reply from osd.2 ever on either front or back, first ping sent 2016-03-21 17:43:47.636418 (cutoff 2016-03-21 17:43:47.937950)　　

　　3. 该OSD节点被map标记为down状态，日志提示是：map wrongly mark me down；
2016-03-21 18:52:58.365106 7f715610e700  0 log_channel(cluster) log [WRN] : map e83 wrongly marked me down　　

　　4. OSD节点无法绑定到网卡6800-7300中任意一个端口；
2016-03-21 18:52:58.366288 7f715610e700 -1 accepter.accepter.bind unable to bind to 192.168.10.210:7300 on any port in range 6800-7300: (99) Cannot assign requested address
2016-03-21 18:52:58.366318 7f715610e700 -1 accepter.accepter.bind was unable to bind. Trying again in 5 seconds　　

　　5. OSD节点准备进入down状态，开始存储文件，进入down状态。
2016-03-21 18:53:18.383806 7f715610e700  0 osd.0 83 prepare_to_stop starting shutdown
2016-03-21 18:53:18.383817 7f715610e700 -1 osd.0 83 shutdown
2016-03-21 18:53:18.383996 7f715610e700 20 osd.0 83  kicking pg 4.76　　

　　然后查看其他mds日志，mon日志均没有查到原因所在，于是去查看系统日志/var/log/messages，查看故障出现那个时间点的日志，这才找到原因所在，日志如下：
Mar 21 17:43:23 cephadmin1 kernel: e1000: enp5s0 NIC Link is Down
Mar 21 17:43:23 cephadmin1 NetworkManager[1021]:   (enp5s0): link disconnected (deferring action for 4 seconds)
Mar 21 17:43:28 cephadmin1 NetworkManager[1021]:   (enp5s0): link disconnected (calling deferred action)
Mar 21 17:43:28 cephadmin1 NetworkManager[1021]:   (enp5s0): device state change: activated -> unavailable (reason 'carrier-changed') [100 20 40]
Mar 21 17:43:28 cephadmin1 NetworkManager[1021]:   (enp5s0): canceled DHCP transaction, DHCP client pid 32494
Mar 21 17:43:28 cephadmin1 NetworkManager[1021]:   (enp5s0): DHCPv6 state changed bound -> done
Mar 21 17:43:28 cephadmin1 avahi-daemon[973]: Withdrawing address record for 192.168.10.210 on enp5s0.
Mar 21 17:43:28 cephadmin1 avahi-daemon[973]: Leaving mDNS multicast group on interface enp5s0.IPv4 with address 192.168.10.210.
Mar 21 17:43:28 cephadmin1 avahi-daemon[973]: Interface enp5s0.IPv4 no longer relevant for mDNS.
Mar 21 17:43:28 cephadmin1 avahi-daemon[973]: Withdrawing address record for 2001:470:4b:34f:207:e9ff:fe08:51 on enp5s0.
Mar 21 17:43:28 cephadmin1 avahi-daemon[973]: Withdrawing address record for fd26:b3dd:d727:0:207:e9ff:fe08:51 on enp5s0.Mar 21 17:43:28 cephadmin1 avahi-daemon[973]: Withdrawing address record for fd26:b3dd:d727::863 on enp5s0.
Mar 21 17:43:28 cephadmin1 NetworkManager[1021]:   Policy set 'enp3s0' (enp3s0) as default for IPv6 routing and DNS.
Mar 21 17:43:28 cephadmin1 dbus-daemon: dbus[987]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Mar 21 17:43:28 cephadmin1 dbus[987]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
Mar 21 17:43:28 cephadmin1 systemd: Starting Network Manager Script Dispatcher Service...
Mar 21 17:43:28 cephadmin1 dbus[987]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Mar 21 17:43:28 cephadmin1 systemd: Started Network Manager Script Dispatcher Service.
Mar 21 17:43:28 cephadmin1 dbus-daemon: dbus[987]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Mar 21 17:43:28 cephadmin1 nm-dispatcher: Dispatching action 'down' for enp5s0
Mar 21 17:43:41 cephadmin1 ceph-osd: 2016-03-21 17:43:41.426082 7efd2c5b4700 -1 osd.3 70 heartbeat_check: no reply from osd.5 since back 2016-03-21 17:43:21.362339 front 2016-03-21 17:43:41.064144 (cutoff 2016-03-21 17:43:21.426080)
Mar 21 17:43:41 cephadmin1 ceph-osd: 2016-03-21 17:43:41.426157 7efd2c5b4700 -1 osd.3 70 heartbeat_check: no reply from osd.6 since back 2016-03-21 17:43:21.362339 front 2016-03-21 17:43:41.064144 (cutoff 2016-03-21 17:43:21.426080)　　

　　从日志中我们可以清楚地看到，这个时间点，ceph集群用来传输数据的网卡down掉了，然后NetworkManager开始处理网卡的一些信息并尝试重启网卡，但是重启失败。突然想起来以前在一篇文章中看到过，CentOS系统中自带的network程序会和GNOME桌面带的NetworManger冲突，导致网卡出现问题。这里应该也是相同的原因。于是关掉NetworkManger并关掉它的自启动程序。
systemctl stop NetworkManger
systemctl disable NetworkManager　　过了两天每天观察，再没出现过单个服务器所有OSD节点全部down掉的故障，说明故障原因确实在这里。