4039bf4 dlm_controld: wrong fencing time comparison

Authored and Committed by teigland 14 years ago
    dlm_controld: wrong fencing time comparison
    
    dlm_controld checks that a failed node has been fenced by comparing the
    time it was fenced to the time it properly joined the cpg.  In one of
    Nate's QE tests, he found a case where the failed node rejoined the cpg
    just before the fencing time was recorded.  This causes dlm_controld to
    get stuck waiting for a fencing to occur when it already has.
    
    1274304702 dlm:ls:clvmd conf 2 0 1 memb 1 4 join left 3
    1274304702 clvmd add_change cg 2 remove nodeid 3 reason 3
    1274304702 clvmd add_change cg 2 counts member 2 joined 0 remove 1 failed 1
    1274304702 clvmd stop_kernel cg 2
    1274304702 write "0" to "/sys/kernel/dlm/clvmd/control"
    1274304702 clvmd check_fencing 3 not fenced add 1274304347 fence 0
    1274304702 dlm:ls:clvmd conf 1 0 1 memb 1 join left 4
    1274304702 clvmd add_change cg 3 remove nodeid 4 reason 3
    1274304702 clvmd add_change cg 3 counts member 1 joined 0 remove 1 failed 1
    1274304702 clvmd check_fencing 4 not fenced add 1274304347 fence 0
    ....
    1274304741 cluster node 3 added
    ...
    1274304752 dlm:ls:clvmd conf 2 1 0 memb 1 3 join 3 left
    1274304752 clvmd add_change cg 4 joined nodeid 3
    1274304752 clvmd add_change cg 4 counts member 2 joined 1 remove 0 failed 0
    1274304754 clvmd receive_start 3:1 len 80
    1274304754 clvmd match_change 3:1 skip 2 sender not member
    1274304754 clvmd match_change 3:1 skip 3 sender not member
    1274304754 clvmd match_change 3:1 matches cg 4
    1274304754 clvmd check_fencing 3 not fenced add 1274304754 fence 1274304753
    1274304754 clvmd check_fencing 4 1274304347 fenced at 1274304753
    ...
    1274304832 dlm:ls:clvmd conf 3 1 0 memb 1 3 4 join 4 left
    1274304832 clvmd add_change cg 5 joined nodeid 4
    1274304832 clvmd add_change cg 5 counts member 3 joined 1 remove 0 failed 0
    1274304832 clvmd receive_start 4:1 len 84
    1274304832 clvmd match_change 4:1 skip cg 2 created 1274304702 cluster add
    12743
    1274304832 clvmd match_change 4:1 skip 3 sender not member
    1274304832 clvmd match_change 4:1 skip 4 sender not member
    1274304832 clvmd match_change 4:1 matches cg 5
    1274304832 clvmd receive_start 3:2 len 84
    1274304832 clvmd match_change 3:2 skip 2 sender not member
    1274304832 clvmd match_change 3:2 skip 3 sender not member
    1274304832 clvmd match_change 3:2 skip 4 already start
    1274304832 clvmd match_change 3:2 matches cg 5
    
    This line: clvmd check_fencing 3 not fenced add 1274304754 fence
    1274304753 shows that 3 was added to the cpg one second after fenced
    recorded that fencing was done.  The fenced log confirms that this is when
    it received the message indicating the 3 was fenced:
    
    1274304753 receive_victim_done 1:3 flags 2 len 80
    1274304753 receive_victim_done 1:3 remove victim 3 time 1274304753 how 2
    
    I've not been able to reproduce this, but I believe the fix is for
    dlm_controld to check that the fencing time is later than the time it saw
    the node fail instead of later than the time it saw the node most recently
    join.
    
    bz 594511
    
    Signed-off-by: David Teigland <teigland@redhat.com>
    
        
file modified
+13 -6