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]: <info>  (enp5s0): link disconnected (deferring action for 4 seconds)
Mar 21 17:43:28 cephadmin1 NetworkManager[1021]: <info>  (enp5s0): link disconnected (calling deferred action)
Mar 21 17:43:28 cephadmin1 NetworkManager[1021]: <info>  (enp5s0): device state change: activated -> unavailable (reason 'carrier-changed') [100 20 40]
Mar 21 17:43:28 cephadmin1 NetworkManager[1021]: <info>  (enp5s0): canceled DHCP transaction, DHCP client pid 32494
Mar 21 17:43:28 cephadmin1 NetworkManager[1021]: <info>  (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]: <info>  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掉的故障,说明故障原因确实在这里。