fuel 6.1自动推送3控高可用centos 6.5 juno环境排错(一)

查看fuel日志:

# less /var/log/docker-logs/remote/node-1.domain.tld/puppet-apply.log

2015-12-25T17:26:22.134118+00:00 debug:  Waiting 600 seconds for service 'vip__public' to start

等待“vip__public”启动超过600秒。“vip__public”是集群的VIP资源:

# crm configure show

primitive vip__public ocf:fuel:ns_IPaddr2
    op stop timeout=30 interval=0
    op monitor timeout=30 interval=3
    op start timeout=30 interval=0
    params ns_iptables_start_rules=false ip=168.1.22.80 ns_iptables_stop_rules=false iptables_stop_rules=false bridge=br-ex ns=haproxy nic=br-ex iptables_start_rules=false other_networks=false gateway=168.1.22.1 base_veth=br-ex-hapr gateway_metric=10 ns_veth=hapr-p iflabel=ka iptables_comment=false cidr_netmask=24
    meta migration-threshold=3 failure-timeout=60 resource-stickiness=1 target-role=Started

某种原因造成“vip__public”资源无法启动:

# crm resource status vip__public

resource vip__public is NOT running

# ping 168.1.22.80

PING 168.1.22.80 (168.1.22.80) 56(84) bytes of data.
From 168.1.22.82 icmp_seq=2 Destination Host Unreachable
From 168.1.22.82 icmp_seq=3 Destination Host Unreachable

尝试手动启动资源仍失败:

# crm resource start vip__public

# crm resource status vip__public

resource vip__public is NOT running

由于/var/log/corosync.log中没有资源无法启动的错误日志,需另想办法排查。

由于vip__public的资源类型是ocf:fuel:ns_IPaddr2,可知创建VIP时,调用了资源代理脚本:

/usr/lib/ocf/resource.d/fuel/ns_IPaddr2

创建OCF测试配置文件/usr/share/resource-agents/ocft/configs/ns_IPaddr2_start,内容如下:

--------------------------------------------------------------------------

# ns_IPaddr2

CONFIG
        Agent ns_IPaddr2
        AgentRoot /usr/lib/ocf/resource.d/fuel
        HangTimeout 20

CASE-BLOCK set_ocf_reskey_env
        Env OCF_RESKEY_iptables_start_rules=false
        Env OCF_RESKEY_iptables_stop_rules=false
        Env OCF_RESKEY_gateway_metric=10
        Env OCF_RESKEY_ns_veth=hapr-p
        Env OCF_RESKEY_base_veth=br-ex-hapr
        Env OCF_RESKEY_gateway=168.1.22.1
        Env OCF_RESKEY_bridge=br-ex
        Env OCF_RESKEY_ip=168.1.22.80
        Env OCF_RESKEY_iflabel=ka
        Env OCF_RESKEY_other_networks=false
        Env OCF_RESKEY_other_cidr_netmask=24
        Env OCF_RESKEY_ns=haproxy
        Env OCF_RESKEY_ns_iptables_start_rules=false
        Env OCF_RESKEY_iptables_comment=false
        Env OCF_RESKEY_nic=br-ex
        Env OCF_RESKEY_ns_iptables_stop_rules=false

CASE "::::begin test start::::"
        Include set_ocf_reskey_env
        AgentRun start OCF_SUCCESS

-----------------------------------------------------------------

编译测试脚本:

# ocft make ns_IPaddr2_start

执行测试脚本:

# ocft test ns_IPaddr2_start

执行测试脚本并没有报错,且成功创建了VIP:

# ping 168.1.22.80

PING 168.1.22.80 (168.1.22.80) 56(84) bytes of data.
64 bytes from 168.1.22.80: icmp_seq=1 ttl=64 time=0.046 ms
64 bytes from 168.1.22.80: icmp_seq=2 ttl=64 time=0.059 ms

怀疑vip__public由于某些原因未调用此脚本。故编辑资源代理脚本:

# cp -a /usr/lib/ocf/resource.d/fuel/ns_IPaddr2 /usr/lib/ocf/resource.d/fuel/ns_IPaddr2.bak

# vi /usr/lib/ocf/resource.d/fuel/ns_IPaddr2

在669行添加:

    668 ## main
    669 echo $__OCF_ACTION>>/root/ns_IPaddr2.log
    670 rc=$OCF_SUCCESS
    671 case $__OCF_ACTION in

经此修改,一旦有调用资源代理脚本发生,就会输出被调用的方法。

尝试手动启动资源并查看资源代理脚本是否被调用:

# crm resource start vip__public

# less /root/ns_IPaddr2.log

发现日志中内容为空,说明资源代理脚本果然没被调用。

为进一步验证,我们尝试操作其它正常的资源:

# crm resource restart vip__management

# less /root/ns_IPaddr2.log

发现日志中有内容,说明正常的资源是有调用资源代理脚本的。

corosync.log中没有日志,ns_IPaddr2资源代理脚本没有被调用,最有可能是vip__public的资源定义有逻辑错误。

集群中的资源定义等相关数据,以xml文件的形式存储在每个节点的/var/lib/pacemaker/cib/cib.xml,其中,对于每个定义的资源,同时可以定义其约束。约束的作用是设置一定条件,若满足或不满足条件,资源可启动或不可启动。

最有可能是约束定义错误。由于当时对cib.xml没有任何了解,无法从中看出任何逻辑错误。

这种情况下,需要知道fuel在推送时,在什么时候出现问题,且出现问题时,puppet做到哪一步。由于是VIP资源出问题,出问题的现象是ping 168.1.22.80不能通,且168.1.22.80并不是安装初期就通不了,利用此特性,如果能够知道168.1.22.80从通到不通的具体时间,就能知道这个时间puppet做了什么动作,导致问题的发生。

在168.1.22.0/24网段的linux服务器,编写一个带时间的ping脚本,内容如下:

----------------------------------------------------

#!/bin/sh
ping 168.1.22.80| while read pong; do echo "$(date +%Y-%m-%d %H:%M:%S) $pong"; done>>/root/ping.log

----------------------------------------------------

重新在fuel推送,且在该服务器在后台执行该脚本:

# nohup /root/ping.sh &

根据日志发现vip__public失效的时间约是23:12:00

2015-12-25 23:11:58 64 bytes from 168.1.22.80: icmp_seq=2844 ttl=64 time=6.70 ms
2015-12-25 23:11:59 64 bytes from 168.1.22.80: icmp_seq=2845 ttl=64 time=1.15 ms
2015-12-25 23:12:00 64 bytes from 168.1.22.80: icmp_seq=2846 ttl=64 time=0.892 ms
2015-12-25 23:12:30 From 168.1.22.205 icmp_seq=2873 Destination Host Unreachable
2015-12-25 23:12:30 From 168.1.22.205 icmp_seq=2874 Destination Host Unreachable
2015-12-25 23:12:30 From 168.1.22.205 icmp_seq=2875 Destination Host Unreachable

在puppet的日志中查看23:12:00发生的事情:

2015-12-25T23:12:00.766102+00:00 debug:  (Cs_rsc_location[loc_ping_vip__public](provider=crm)) {}
2015-12-25T23:12:00.768631+00:00 notice:  (/Stage[main]/Main/Cluster::Virtual_ip_ping[vip__public]/Cs_rsc_location[loc_ping_vip__public]/ensure) created
2015-12-25T23:12:00.775187+00:00 debug:  Executing '/usr/sbin/pcs property show dc-version'
2015-12-25T23:12:03.157766+00:00 debug:  (Cs_rsc_location[loc_ping_vip__public](provider=crm)) Evaluating {:cib=>"ping_vip__public", :node_score=>nil, :primitive=>"vip__public", :name=>"loc_ping_vip__public", :rules=>[{:expressions=>[{:value=>"or", :operation=>"pingd", :attribute=>"not_defined"}, {:value=>"0", :operation=>"lte", :attribute=>"pingd"}], :boolean=>"", :score=>"-inf"}], :node_name=>nil, :ensure=>:present}
2015-12-25T23:12:03.157951+00:00 debug:  (Cs_rsc_location[loc_ping_vip__public](provider=crm)) creating location with command
2015-12-25T23:12:03.157951+00:00 debug:  (Cs_rsc_location[loc_ping_vip__public](provider=crm))  location loc_ping_vip__public vip__public rule -inf: not_defined pingd or pingd lte 0  
2015-12-25T23:12:03.157951+00:00 debug:  (Cs_rsc_location[loc_ping_vip__public](provider=crm)) trying to delete old shadow if exists
2015-12-25T23:12:03.157951+00:00 debug:  Executing '/usr/sbin/crm_shadow -b -f -D location_loc_ping_vip__public'
2015-12-25T23:12:03.206974+00:00 debug:  (Cs_rsc_location[loc_ping_vip__public](provider=crm)) delete failed but proceeding anyway
2015-12-25T23:12:03.207226+00:00 debug:  Executing '/usr/sbin/crm_shadow -b -c location_loc_ping_vip__public'
2015-12-25T23:12:04.355222+00:00 debug:  (Cs_rsc_location[loc_ping_vip__public](provider=crm)) no difference - nothing to apply
2015-12-25T23:12:04.355979+00:00 debug:  (/Stage[main]/Main/Cluster::Virtual_ip_ping[vip__public]/Cs_rsc_location[loc_ping_vip__public]) The container Cluster::Virtual_ip_ping[vip__public] will propagate my refresh event
2015-12-25T23:12:04.356660+00:00 info:  (/Stage[main]/Main/Cluster::Virtual_ip_ping[vip__public]/Cs_rsc_location[loc_ping_vip__public]) Evaluated in 6.21 seconds
2015-12-25T23:12:04.357718+00:00 info:  (/Stage[main]/Main/Cluster::Virtual_ip_ping[vip__public]/Service[ping_vip__public]) Starting to evaluate the resource
2015-12-25T23:12:04.358951+00:00 debug:  Waiting 600 seconds for Pacemaker to become online

由于当时对crm不是很了解,看不懂日志到底做什么了,只大概看懂了puppet对cib进行了一定的操作,看来需要继续跟踪cib的变化。

重新用fuel推送,在controller1,添加脚本不断地导出cib.xml的内容:

------------------------------------------------------------------------

#!/bin/sh

STR_TIME=''
STR_PATH=''
STR_MD5_C=''
STR_MD5=''

mkdir -p /root/cib
while :
do
  STR_TIME=$(date +%Y%m%d%H%M%S)
  STR_PATH=/root/cib/cib_$STR_TIME.xml
  cibadmin --query>$STR_PATH
  STR_MD5_C=$(md5sum $STR_PATH|awk '{print $1}')
  if [ "$STR_MD5" != "$STR_MD5_C" ]; then
    STR_MD5=$STR_MD5_C
    mv $STR_PATH /root/cib/cib_$STR_TIME.${STR_MD5:0-4}
  else
    rm -f $STR_PATH
  fi
  sleep 1s
done

--------------------------------------------------------------------------

在controller1后台执行该脚本:

# nohup /root/cib.sh &

从ping 168.1.22.80的脚本看出,出现问题的时间点大概是23:12:00,查看controller1的/root/cib目录:

cib_20151225231150.1fbc
cib_20151225231201.b4f1
cib_20151225231203.09b2

cib_20151225231150.1fbc:
<cib crm_feature_set="3.0.9" validate-with="pacemaker-2.0" epoch="119" num_updates="3" admin_epoch="0" cib-last-written="Fri Dec 25 23:11:48 2015" have-quorum="1" dc-uuid="11">
 
cib_20151225231201.b4f1:
<cib crm_feature_set="3.0.9" validate-with="pacemaker-2.0" epoch="120" num_updates="0" admin_epoch="0" cib-last-written="Fri Dec 25 23:12:00 2015" have-quorum="1" dc-uuid="11">
 
 
两个文件用Beybond Compare比较,发现第二个文件只多了:
    399       <rsc_location id="loc_ping_vip__public" rsc="vip__public">
    400         <rule score="-INFINITY" id="loc_ping_vip__public-rule" boolean-op="or">
    401           <expression operation="not_defined" id="loc_ping_vip__public-rule-expression" attribute="pingd"/>
    402           <expression value="0" operation="lte" id="loc_ping_vip__public-rule-expression-0" attribute="pingd"/>
    403         </rule>
    404       </rsc_location>

loc_ping_vip__public是cib.xml中约束部分(constraints)的内容,与我的猜想吻合。

导出错误发生后的约束部分内容:

# cibadmin --query --scope=constraints>/root/constraints.xml

编辑constraints.xml,删除loc_ping_vip__public的定义,并保存到自己的电脑。

重新用fuel推送,在controller1,添加脚本等待cib.xml的内容中出现“loc_ping_vip__public”:

---------------------------------------------------------------------------

#!/bin/sh
r=1
while [ "$r" = 1 ]; do
  cibadmin --query --scope=constraints>/root/t.xml
  grep loc_ping_vip__public /root/t.xml
  r=$?
  sleep 1s
done
sleep 29s
cibadmin --replace --scope=constraints --xml-file /root/constraints.xml

---------------------------------------------------------------------------

推送成功。

推送成功,是相当于手动修改了puppet推出的内容,在网络上没有找到别人有相同的问题,且通过修改puppet的方法解决这个问题,这问题应该不是一个bug。需要理解loc_ping_vip__public定义的内容到底是什么意思。

经过下列连接的学习:

http://clusterlabs.org/doc/en-US/Pacemaker/1.1/html-single/Pacemaker_Explained/#_scores

http://clusterlabs.org/doc/en-US/Pacemaker/1.1/html-single/Pacemaker_Explained/#_rule_properties

http://clusterlabs.org/doc/en-US/Pacemaker/1.1/html/Pacemaker_Explained/_moving_resources_due_to_connectivity_changes.html

http://clusterlabs.org/doc/en-US/Pacemaker/1.1/html/Pacemaker_Explained/_tell_pacemaker_how_to_interpret_the_connectivity_data.html

明白了loc_ping_vip__public定义的内容到底是什么意思:

    399       <rsc_location id="loc_ping_vip__public" rsc="vip__public">
    400         <rule score="-INFINITY" id="loc_ping_vip__public-rule" boolean-op="or">
    401           <expression operation="not_defined" id="loc_ping_vip__public-rule-expression" attribute="pingd"/>
    402           <expression value="0" operation="lte" id="loc_ping_vip__public-rule-expression-0" attribute="pingd"/>
    403         </rule>
    404       </rsc_location>

rsc="vip__public"指约束的对象是vip__public资源;

boolean-op="or"指每条表达式(<expression... />)的布尔值进行“或”运算;

rule score="-INFINITY"指最终结果如果是“True”(此处则为或运算的结果),则被约束的对象不能启动;

表达式 1:<expression ... not_defined ... />,此条表达式检查资源中是否缺少定义了属性为“pingd”的资源,结果为假,因为是属性为“pingd”的资源:

      <clone id="clone_ping_vip__public">
        <primitive class="ocf" type="ping" id="ping_vip__public" provider="pacemaker">
          <operations>
            <op timeout="30" name="monitor" interval="20" id="ping_vip__public-monitor-20"/>
          </operations>
          <instance_attributes id="ping_vip__public-instance_attributes">
            <nvpair value="3s" name="timeout" id="ping_vip__public-instance_attributes-timeout"/>
            <nvpair value="30s" name="dampen" id="ping_vip__public-instance_attributes-dampen"/>
            <nvpair value="1000" name="multiplier" id="ping_vip__public-instance_attributes-multiplier"/>
            <nvpair value="168.1.22.1" name="host_list" id="ping_vip__public-instance_attributes-host_list"/>
          </instance_attributes>
        </primitive>
      </clone>

表达式2:<expression ... value="0" operation="lte" ... />,此条表达式检查属性为“pingd”的资源。属性为“pingd”的资源是用来检查某个IP能不能ping通的,能ping通返回0。这里lte 0表示返回值不为0时,表达式返回真。从ping_vip__public的资源定义看出,它ping的是168.1.22.1,是我环境中的网关,我环境中其实是没有网关的,所以ping不通,所以此条表达式的最终结果是真,或运算后是真,则被约束对象不能启动。

综上,约束定义loc_ping_vip__public是用来测试网关能不能通的,只有网关能通的节点才能启动vip__public,难怪删除loc_ping_vip__public后推送是成功的,也难怪网络上没人遇到我这个问题,因为他们的网络环境网关是能通的!

在网络上找到了相同问题:

http://irclog.perlgeek.de/fuel-dev/2015-01-28

PS:再解释一下什么是“属性为pingd的资源”,就是类型是“ocf:pacemaker:ping”的资源,请用命令“crm configure show”查看,一般集群中至少要有一个这种类型的资源。

用fuel重推了好几次才排查出问题,且最后排查出的问题竟然是网关ping不通。。。

原文地址:https://www.cnblogs.com/endoresu/p/5083353.html