Bug 360541

Summary: On a two nodes cluster, when a member reboot, services are not switching on the active node
Product: [Retired] Red Hat Cluster Suite Reporter: Eric MAGALLON <eric.magallon-external>
Component: clumanagerAssignee: Lon Hohberger <lhh>
Status: CLOSED ERRATA QA Contact: Cluster QE <mspqa-list>
Severity: high Docs Contact:
Priority: low    
Version: 3CC: bmr, cluster-maint, rkenna
Target Milestone: ---   
Target Release: ---   
Hardware: i686   
OS: Linux   
Whiteboard:
Fixed In Version: RHBA-2008-0091 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2008-02-07 18:31:42 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
Fix. none

Description Eric MAGALLON 2007-10-31 16:48:07 UTC
Description of problem:

We have a cluster with two members and five services. Services are started on
the two nodes :

[root@OsaveAppli1 root]# clustat
Cluster Status - m3g-pclustapp                                         16:47:51
Cluster Quorum Incarnation #6
Shared State: Shared Raw Device Driver v1.2

  Member             Status    
  ------------------ ----------
  m3g-pappnode1      Active     <-- You are here
  m3g-pappnode2      Inactive             

  Service        Status   Owner (Last)     Last Transition Chk Restarts
  -------------- -------- ---------------- --------------- --- --------
  sg_products    started  m3g-pappnode2    15:04:19 Oct 31  90        0
  sg_syncml      started  m3g-pappnode1    15:05:03 Oct 31  90        0
  sg_gui         started  m3g-pappnode1    15:05:45 Oct 31  90        0
  sg_frwk        started  m3g-pappnode1    15:02:31 Oct 31  90        0
  sg_jboss       started  m3g-pappnode2    15:05:03 Oct 31  90        0

We are rebooting the second node (m3g-pappnode2) and hope to see the services
sg_products and sg_jboss relocated on the first node.

It is not the case.

Here the logs of /var/log/messages of the first node :

Oct 31 16:45:39 OsaveAppli1 su(pam_unix)[6391]: session closed for user adm3ggc1
Oct 31 16:45:39 OsaveAppli1 su(pam_unix)[6149]: session opened for user root by
adm3ggc1(uid=10000)
Oct 31 16:45:40 OsaveAppli1 su(pam_unix)[6462]: session closed for user adm3ggc1
Oct 31 16:46:11 OsaveAppli1 kernel: bnx2: eth3 NIC Link is Down
Oct 31 16:46:13 OsaveAppli1 kernel: bnx2: eth3 NIC Link is Up, 100 Mbps full
duplex, receive & transmit flow control ON
Oct 31 16:46:14 OsaveAppli1 su(pam_unix)[6874]: session opened for user adm3ggc1
by (uid=0)
Oct 31 16:46:15 OsaveAppli1 su(pam_unix)[6874]: session closed for user adm3ggc1
Oct 31 16:46:27 OsaveAppli1 cluquorumd[21366]: <warning> Membership reports #1
as down, but disk reports as up: State uncertain!
Oct 31 16:46:27 OsaveAppli1 clusvcmgrd[21378]: <warning> Member m3g-pappnode2's
state is uncertain: Some services may be unavailable!
Oct 31 16:46:27 OsaveAppli1 kernel: bnx2: eth3 NIC Link is Down
Oct 31 16:46:30 OsaveAppli1 kernel: bnx2: eth3 NIC Link is Up, 1000 Mbps full
duplex, receive & transmit flow control ON
Oct 31 16:46:41 OsaveAppli1 cluquorumd[21366]: <warning> --> Commencing STONITH <--
Oct 31 16:46:41 OsaveAppli1 cluquorumd[21366]: <warning> STONITH: Falsely
claiming that m3g-pappnode2 has been fenced
Oct 31 16:46:41 OsaveAppli1 cluquorumd[21366]: <crit> STONITH: Data integrity
may be compromised!
Oct 31 16:47:13 OsaveAppli1 su(pam_unix)[7187]: session opened for user adm3ggc1
by (uid=0)
Oct 31 16:47:14 OsaveAppli1 su(pam_unix)[7268]: session opened for user adm3ggc1
by (uid=0)
Oct 31 16:47:14 OsaveAppli1 su(pam_unix)[7187]: session closed for user adm3ggc1
Oct 31 16:47:16 OsaveAppli1 su(pam_unix)[7268]: session closed for user adm3ggc1
Oct 31 16:47:50 OsaveAppli1 su(pam_unix)[7640]: session opened for user adm3ggc1
by (uid=0)
Oct 31 16:47:50 OsaveAppli1 su(pam_unix)[7640]: session closed for user adm3ggc1
Oct 31 16:48:53 OsaveAppli1 su(pam_unix)[7937]: session opened for user adm3ggc1
by (uid=0)
Oct 31 16:48:53 OsaveAppli1 su(pam_unix)[8012]: session opened for user adm3ggc1
by (uid=0)
Oct 31 16:48:53 OsaveAppli1 su(pam_unix)[7937]: session closed for user adm3ggc1
Oct 31 16:48:55 OsaveAppli1 su(pam_unix)[8012]: session closed for user adm3ggc1
Oct 31 16:49:24 OsaveAppli1 kernel: bnx2: eth3 NIC Link is Down
Oct 31 16:49:26 OsaveAppli1 kernel: bnx2: eth3 NIC Link is Up, 1000 Mbps full
duplex, receive & transmit flow control ON
Oct 31 16:49:29 OsaveAppli1 su(pam_unix)[8386]: session opened for user adm3ggc1
by (uid=0)
Oct 31 16:49:29 OsaveAppli1 su(pam_unix)[8386]: session closed for user adm3ggc1
Oct 31 16:49:32 OsaveAppli1 clumembd[21369]: <notice> Member m3g-pappnode2 UP
Oct 31 16:50:31 OsaveAppli1 su(pam_unix)[8706]: session opened for user adm3ggc1
by (uid=0)
Oct 31 16:50:31 OsaveAppli1 su(pam_unix)[8780]: session opened for user adm3ggc1
by (uid=0)
Oct 31 16:50:31 OsaveAppli1 su(pam_unix)[8706]: session closed for user adm3ggc1

After reboot finished on the second node, the products are restarted on the same
node.

[root@OsaveAppli1 root]# clustat
Cluster Status - m3g-pclustapp                                         16:54:25
Cluster Quorum Incarnation #8
Shared State: Shared Raw Device Driver v1.2

  Member             Status    
  ------------------ ----------
  m3g-pappnode1      Active     <-- You are here
  m3g-pappnode2      Active               

  Service        Status   Owner (Last)     Last Transition Chk Restarts
  -------------- -------- ---------------- --------------- --- --------
  sg_products    started  m3g-pappnode2    16:45:55 Oct 31  90        0
  sg_syncml      started  m3g-pappnode1    15:05:03 Oct 31  90        0
  sg_gui         started  m3g-pappnode1    15:05:45 Oct 31  90        0
  sg_frwk        started  m3g-pappnode1    15:02:31 Oct 31  90        0
  sg_jboss       started  m3g-pappnode2    16:45:55 Oct 31  90        0


Version-Release number of selected component (if applicable):

clumanager-1.2.35.2-1

How reproducible:

Steps to Reproduce:
1. Reboot a node with services started on it.
2. You can see services are not relocated
3. After reboot, services are restarted on the same node
  
Actual results:

Services on the restarted node are not relocated on the active node.

Expected results:

Services on the restarted node must be relocated on the active node.

Additional info:

Comment 7 Lon Hohberger 2007-10-31 20:22:09 UTC
Oct 31 14:59:44 magenta clusvcmgrd[2150]: <debug> Evaluating service foo6, state
started, owner member1
Oct 31 14:59:44 magenta clusvcmgrd[2150]: <debug> Service foo6 request 3 
Oct 31 14:59:44 magenta clusvcmgrd[28362]: <debug> [C] Pid 28362 handling start
request for service foo6
Oct 31 14:59:44 magenta clusvcmgrd[28362]: <debug> Starting service 6 - flags
0x00000000
Oct 31 14:59:44 magenta clusvcmgrd[28362]: <debug> Handling start request for
service foo6 
Oct 31 14:59:44 magenta clusvcmgrd[2150]: <debug> [M] Pid 28362 -> start for
service foo6
Oct 31 14:59:44 magenta clusvcmgrd[28362]: <debug> Service is running on member
member1. 
Oct 31 14:59:44 magenta clusvcmgrd[2150]: <debug> Evaluating service foo7, state
started, owner member1
Oct 31 14:59:44 magenta clusvcmgrd[2150]: <debug> Service foo7 request 3 
Oct 31 14:59:44 magenta clusvcmgrd[28363]: <debug> [C] Pid 28363 handling start
request for service foo7
Oct 31 14:59:44 magenta clusvcmgrd[2150]: <debug> [M] Pid 28363 -> start for
service foo7 
Oct 31 14:59:44 magenta clusvcmgrd[2150]: <info> State change: member0 DOWN 
Oct 31 14:59:44 magenta clusvcmgrd[28363]: <debug> Starting service 7 - flags
0x00000000 
Oct 31 14:59:44 magenta clusvcmgrd[28363]: <debug> Handling start request for
service foo7 
Oct 31 14:59:44 magenta clusvcmgrd[28363]: <debug> Service is running on member
member1.


So, it evaluated the service incorrectly - it looks like the previously-recorded
panic mask is used, which needs to be cleared in this case after getting a real
node-down event from the quorum daemon.

Comment 8 Lon Hohberger 2007-10-31 20:24:58 UTC
Oct 31 15:07:32 magenta clumembd[2097]: <info> Membership View #33:0x00000001 
Oct 31 15:07:33 magenta cluquorumd[2079]: <warning> Membership reports #1 as
down, but disk reports as up: State uncertain! 
Oct 31 15:07:33 magenta cluquorumd[2079]: <warning> --> Commencing STONITH <-- 
Oct 31 15:07:34 magenta clusvcmgrd[2125]: <info> Quorum Event: View #74 0x00000001 
Oct 31 15:07:34 magenta clusvcmgrd[2125]: <warning> Member member1's state is
uncertain: Some services may be unavailable!
Oct 31 15:07:39 magenta kernel: e100: eth1: e100_watchdog: link down
Oct 31 15:07:54 magenta cluquorumd[2079]: <warning> --> Commencing STONITH <-- 
Oct 31 15:07:56 magenta cluquorumd[2079]: Power to NPS outlet(s) 6 turned /Off.
Oct 31 15:07:56 magenta cluquorumd[2079]: <notice> STONITH: member1 has been
fenced! 
Oct 31 15:07:57 magenta cluquorumd[2079]: Power to NPS outlet(s) 6 turned /On.
Oct 31 15:07:57 magenta cluquorumd[2079]: <notice> STONITH: member1 is no longer
fenced off. 
Oct 31 15:07:58 magenta clusvcmgrd[2125]: <info> Quorum Event: View #76 0x00000001 
Oct 31 15:07:58 magenta clusvcmgrd[3362]: <notice> Taking over service foo3 from
down member member1 
Oct 31 15:07:58 magenta clusvcmgrd[3374]: <notice> Taking over service foo4 from
down member member1 
Oct 31 15:07:58 magenta clusvcmgrd: [3363]: <notice> service notice: Starting
service foo3 ... 
Oct 31 15:07:58 magenta clusvcmgrd[3415]: <notice> Taking over service foo5 from
down member member1 
Oct 31 15:07:58 magenta clusvcmgrd[3440]: <notice> Taking over service foo6 from
down member member1 
Oct 31 15:07:58 magenta clusvcmgrd: [3404]: <notice> service notice: Starting
service foo4 ... 
Oct 31 15:07:58 magenta clusvcmgrd[2125]: <info> State change: member0 DOWN 
Oct 31 15:07:58 magenta clusvcmgrd[3473]: <notice> Taking over service foo7 from
down member member1 
Oct 31 15:07:59 magenta clusvcmgrd: [3425]: <notice> service notice: Starting
service foo5 ... 
Oct 31 15:07:59 magenta clusvcmgrd: [3470]: <notice> service notice: Starting
service foo6 ... 
Oct 31 15:07:59 magenta clusvcmgrd: [3479]: <notice> service notice: Starting
service foo7 ... 
Oct 31 15:07:59 magenta clusvcmgrd: [3363]: <notice> service notice: Started
service foo3 ... 
Oct 31 15:07:59 magenta clusvcmgrd: [3404]: <notice> service notice: Started
service foo4 ... 
Oct 31 15:07:59 magenta clusvcmgrd: [3425]: <notice> service notice: Started
service foo5 ... 
Oct 31 15:07:59 magenta clusvcmgrd: [3479]: <notice> service notice: Started
service foo7 ... 
Oct 31 15:08:00 magenta clusvcmgrd: [3470]: <notice> service notice: Started
service foo6 ... 

Logs with patch

Comment 9 Lon Hohberger 2007-10-31 20:27:30 UTC
Note that my reproduction case was not tied to any normal reboot case: I had to
first kill the node's ethernet link then either kill -9 all of the cluster
daemons or do 'reboot -fn'.



Comment 10 Lon Hohberger 2007-10-31 20:28:39 UTC
Created attachment 244881 [details]
Fix.

Comment 11 Lon Hohberger 2007-10-31 21:47:21 UTC
Unofficial test packages here (fixes 2 other bugs too):

http://people.redhat.com/lhh/packages.html
http://people.redhat.com/lhh/patches.html


Comment 13 Eric MAGALLON 2007-11-01 08:48:14 UTC
Thanks Lon for your quickly fix :)

I will install and test it next monday on our test platform. I will make you a
return on test result.


Comment 14 Lon Hohberger 2007-11-01 14:13:04 UTC
Debuginfo packages are there, too, but not on the page:

http://people.redhat.com/lhh/clumanager-debuginfo-1.2.36-1.i386.rpm
http://people.redhat.com/lhh/clumanager-debuginfo-1.2.36-1.x86_64.rpm

Comment 15 Eric MAGALLON 2007-11-05 09:16:34 UTC
Lon,

The link to package i686 is broken :
http://people.redhat.com/lhh/clumanager-1.2.36-1.i686.rpm

Can you provide it to me ?

Thanks.

Comment 16 Eric MAGALLON 2007-11-07 08:21:26 UTC
Lon, 

Finally, I have downloaded the package, his true name is
clumanager-1.2.36-1.i386.rpm.

After installation, the tests are successful for reboot and shutdown.

Can you inform us when an official delivery will be available from Redhat ?

Regards. 

Comment 17 Lon Hohberger 2007-11-08 18:34:05 UTC
Sorry about that; I fixed the link.

Because Red Hat Enterprise Linux 3 and associated layered products (including
Red Hat Cluster Suite 3) are in maintenance mode, you need to make a request
through Red Hat Support if you need official packages:

http://www.redhat.com/apps/support/

Comment 22 Lon Hohberger 2008-02-01 19:47:10 UTC
This will be going out as an erratum shortly.  The package will be 1.2.37-1.1;
watch for it on RHN.

Comment 24 errata-xmlrpc 2008-02-07 18:31:42 UTC
An advisory has been issued which should help the problem
described in this bug report. This report is therefore being
closed with a resolution of ERRATA. For more information
on the solution and/or where to find the updated files,
please follow the link below. You may reopen this bug report
if the solution does not work for you.

http://rhn.redhat.com/errata/RHBA-2008-0091.html