On Mon, Apr 27, 2009 at 4:14 PM, Jiann-Ming Su <[email protected]> wrote:
> On Mon, Apr 27, 2009 at 3:51 PM, Jiann-Ming Su <[email protected]> wrote:
>> On Sat, Apr 25, 2009 at 8:15 AM, Brandon Allhands <[email protected]> 
>> wrote:
>>> Is named set to startup outside of heartbeat? chkconfig --list named?
>>>
>>
>> No, the named initscript is set to off.
>>
>>
>
> In the cib.xml, here's the difference I see:
>
>         <primitive id="named" class="lsb" type="named" provider="heartbeat">
>           <operations>
>             <op id="a5004e78-2241-4546-8906-02a054b48edf"
> name="monitor" interval="120s" timeout="60s" start_delay="0"
> disabled="false" role="Started"/>
>           </operations>
>         </primitive>
>         <primitive class="lsb" id="dhcpd_4" provider="heartbeat" type="dhcpd">
>           <operations>
>             <op id="dhcpd_4_mon" interval="120s" name="monitor"
> timeout="60s" start_delay="0" disabled="false" role="Started"/>
>           </operations>
>           <meta_attributes id="dhcpd_4_meta_attrs">
>             <attributes/>
>           </meta_attributes>
>           <instance_attributes id="dhcpd_4">
>             <attributes/>
>           </instance_attributes>
>         </primitive>
>
> The named instance doesn't have the meta_attributes or
> instance_attributes.  Also, I added named using the gui, while dhcp
> and the others were added using the haresources2cib.py script.  Not
> sure if any of that makes a difference on the behavior I've observed.

Ran into a situation today where the active node in two different
clusters had a problem monitoring named which caused each cluster to
go into a strange state where dhcpd  was down and named was reporting
down but was actually up.

Here's what I was able to find in the messages:

May 18 14:20:39 dhcp2-admin lrmd: [2893]: WARN: named:monitor process
(PID 27438) timed out (try 1).  Killing with signal SIGTERM (15).
May 18 14:20:39 dhcp2-admin lrmd: [2893]: WARN: operation monitor[142]
on lsb::named::named for client 2896, its parameters:
CRM_meta_interval=[120000] CRM_meta_start_delay=[0] CRM_meta_role=[S
tarted] CRM_meta_id=[473ee35e-ead0-49e6-b021-61a0e36d2704]
CRM_meta_timeout=[60000] crm_feature_set=[2.0]
CRM_meta_disabled=[false] CRM_meta_name=[monitor] : pid [27438] timed
out
May 18 14:20:39 dhcp2-admin crmd: [2896]: ERROR: process_lrm_event:
LRM operation named_monitor_120000 (142) Timed Out (timeout=60000ms)
May 18 14:20:40 dhcp2-admin crmd: [2896]: info: do_lrm_rsc_op:
Performing op=lease-parser_5_stop_0
key=28:1:43858383-d401-49a0-8852-e5e37418c2b9)
May 18 14:20:40 dhcp2-admin lrmd: [2893]: info: rsc:lease-parser_5: stop
May 18 14:20:40 dhcp2-admin lrmd: [27900]: WARN: For LSB init script,
no additional parameters are needed.
May 18 14:20:40 dhcp2-admin crmd: [2896]: info: process_lrm_event: LRM
operation lease-parser_5_monitor_120000 (call=146, rc=-2) Cancelled
May 18 14:20:40 dhcp2-admin lrmd: [2893]: info: RA output:
(lease-parser_5:stop:stdout) Stopping lease-parser:
May 18 14:20:41 dhcp2-admin lrmd: [2893]: info: RA output:
(lease-parser_5:stop:stdout) [  OK
May 18 14:20:41 dhcp2-admin lrmd: [2893]: info: RA output:
(lease-parser_5:stop:stdout) ]
May 18 14:20:41 dhcp2-admin lrmd: [2893]: info: RA output:
(lease-parser_5:stop:stdout)
May 18 14:20:41 dhcp2-admin crmd: [2896]: info: process_lrm_event: LRM
operation lease-parser_5_stop_0 (call=147, rc=0) complete
May 18 14:20:42 dhcp2-admin crmd: [2896]: info: do_lrm_rsc_op:
Performing op=dhcpd_4_stop_0
key=26:1:43858383-d401-49a0-8852-e5e37418c2b9)
May 18 14:20:42 dhcp2-admin lrmd: [2893]: info: rsc:dhcpd_4: stop
May 18 14:20:42 dhcp2-admin lrmd: [27919]: WARN: For LSB init script,
no additional parameters are needed.
May 18 14:20:42 dhcp2-admin crmd: [2896]: info: process_lrm_event: LRM
operation dhcpd_4_monitor_120000 (call=144, rc=-2) Cancelled
May 18 14:20:42 dhcp2-admin lrmd: [2893]: info: RA output:
(dhcpd_4:stop:stdout) Shutting down dhcpd:
May 18 14:20:47 dhcp2-admin lrmd: [2893]: info: RA output:
(dhcpd_4:stop:stdout) [FAILED]
May 18 14:20:47 dhcp2-admin lrmd: [2893]: info: RA output:
(dhcpd_4:stop:stdout)
May 18 14:20:47 dhcp2-admin crmd: [2896]: ERROR: process_lrm_event:
LRM operation dhcpd_4_stop_0 (call=148, rc=1) Error unknown error
May 18 14:23:39 dhcp2-admin lrmd: [2893]: WARN: named:monitor process
(PID 28698) timed out (try 1).  Killing with signal SIGTERM (15).
May 18 14:23:39 dhcp2-admin lrmd: [2893]: WARN: operation monitor[142]
on lsb::named::named for client 2896, its parameters:
CRM_meta_interval=[120000] CRM_meta_start_delay=[0] CRM_meta_role=[S
tarted] CRM_meta_id=[473ee35e-ead0-49e6-b021-61a0e36d2704]
CRM_meta_timeout=[60000] crm_feature_set=[2.0]
CRM_meta_disabled=[false] CRM_meta_name=[monitor] : pid [28698] timed
out
May 18 14:23:39 dhcp2-admin crmd: [2896]: ERROR: process_lrm_event:
LRM operation named_monitor_120000 (142) Timed Out (timeout=60000ms)
May 18 14:26:39 dhcp2-admin lrmd: [2893]: WARN: named:monitor process
(PID 29834) timed out (try 1).  Killing with signal SIGTERM (15).
May 18 14:26:39 dhcp2-admin lrmd: [2893]: WARN: operation monitor[142]
on lsb::named::named for client 2896, its parameters:
CRM_meta_interval=[120000] CRM_meta_start_delay=[0] CRM_meta_role=[S
tarted] CRM_meta_id=[473ee35e-ead0-49e6-b021-61a0e36d2704]
CRM_meta_timeout=[60000] crm_feature_set=[2.0]
CRM_meta_disabled=[false] CRM_meta_name=[monitor] : pid [29834] timed
out
May 18 14:26:39 dhcp2-admin crmd: [2896]: ERROR: process_lrm_event:
LRM operation named_monitor_120000 (142) Timed Out (timeout=60000ms)
May 18 14:28:37 dhcp2-admin cib: [2892]: info: cib_stats: Processed 16
operations (1875.00us average, 0% utilization) in the last 10min
May 18 14:29:39 dhcp2-admin lrmd: [2893]: WARN: named:monitor process
(PID 31059) timed out (try 1).  Killing with signal SIGTERM (15).
May 18 14:29:39 dhcp2-admin lrmd: [2893]: WARN: operation monitor[142]
on lsb::named::named for client 2896, its parameters:
CRM_meta_interval=[120000] CRM_meta_start_delay=[0] CRM_meta_role=[S
tarted] CRM_meta_id=[473ee35e-ead0-49e6-b021-61a0e36d2704]
CRM_meta_timeout=[60000] crm_feature_set=[2.0]
CRM_meta_disabled=[false] CRM_meta_name=[monitor] : pid [31059] timed
out
May 18 14:29:39 dhcp2-admin crmd: [2896]: ERROR: process_lrm_event:
LRM operation named_monitor_120000 (142) Timed Out (timeout=60000ms)
May 18 14:30:43 dhcp2-admin lrmd: [2893]: WARN: G_SIG_dispatch:
Dispatch function for SIGCHLD was delayed 1000 ms (> 100 ms) before
being called (GSource: 0x9015368)
May 18 14:30:43 dhcp2-admin lrmd: [2893]: info: G_SIG_dispatch:
started at 901261472 should have started at 901261372
May 18 14:32:39 dhcp2-admin lrmd: [2893]: WARN: named:monitor process
(PID 32197) timed out (try 1).  Killing with signal SIGTERM (15).
May 18 14:32:39 dhcp2-admin lrmd: [2893]: WARN: operation monitor[142]
on lsb::named::named for client 2896, its parameters:
CRM_meta_interval=[120000] CRM_meta_start_delay=[0] CRM_meta_role=[S
tarted] CRM_meta_id=[473ee35e-ead0-49e6-b021-61a0e36d2704]
CRM_meta_timeout=[60000] crm_feature_set=[2.0]
CRM_meta_disabled=[false] CRM_meta_name=[monitor] : pid [32197] timed
out
May 18 14:32:39 dhcp2-admin crmd: [2896]: ERROR: process_lrm_event:
LRM operation named_monitor_120000 (142) Timed Out (timeout=60000ms)
May 18 15:04:42 dhcp2-admin lrmd: [2893]: WARN: G_SIG_dispatch:
Dispatch function for SIGCHLD was delayed 1000 ms (> 100 ms) before
being called (GSource: 0x9015368)
May 18 15:04:42 dhcp2-admin lrmd: [2893]: info: G_SIG_dispatch:
started at 901465342 should have started at 901465242
May 18 15:10:46 dhcp2-admin lrmd: [2893]: WARN: G_SIG_dispatch:
Dispatch function for SIGCHLD was delayed 1000 ms (> 100 ms) before
being called (GSource: 0x9015368)
May 18 15:10:46 dhcp2-admin lrmd: [2893]: info: G_SIG_dispatch:
started at 901501652 should have started at 901501552

And from the other cluster:

May 18 14:18:12 dhcp2-a lrmd: [2929]: WARN: G_SIG_dispatch: Dispatch
function for SIGCHLD was delayed 1000 ms (> 100 ms) before being
called (GSource: 0x8ad7368)
May 18 14:18:12 dhcp2-a lrmd: [2929]: info: G_SIG_dispatch: started at
936276860 should have started at 936276760
May 18 14:18:47 dhcp2-a lrmd: [2929]: WARN: named:monitor process (PID
2755) timed out (try 1).  Killing with signal SIGTERM (15).May 18
14:18:47 dhcp2-a lrmd: [2929]: WARN: operation monitor[75] on
lsb::named::named for client 2932, its parameters:
CRM_meta_interval=[120000] CRM_meta_start_delay=[0]
CRM_meta_role=[Started] C
RM_meta_id=[a5004e78-2241-4546-8906-02a054b48edf]
CRM_meta_timeout=[60000] crm_feature_set=[2.0]
CRM_meta_disabled=[false] CRM_meta_name=[monitor] : pid [2755] timed
out
May 18 14:18:47 dhcp2-a crmd: [2932]: ERROR: process_lrm_event: LRM
operation named_monitor_120000 (75) Timed Out (timeout=60000ms)
May 18 14:18:48 dhcp2-a crmd: [2932]: info: do_lrm_rsc_op: Performing
op=lease-parser_5_stop_0
key=28:179:68fc3118-d505-4de6-b318-d3a9832f1869)
May 18 14:18:48 dhcp2-a lrmd: [2929]: info: rsc:lease-parser_5: stop
May 18 14:18:48 dhcp2-a lrmd: [3255]: WARN: For LSB init script, no
additional parameters are needed.
May 18 14:18:48 dhcp2-a crmd: [2932]: info: process_lrm_event: LRM
operation lease-parser_5_monitor_120000 (call=79, rc=-2) Cancelled
May 18 14:18:48 dhcp2-a lrmd: [2929]: info: RA output:
(lease-parser_5:stop:stdout) Stopping lease-parser:
May 18 14:18:49 dhcp2-a lrmd: [2929]: info: RA output:
(lease-parser_5:stop:stdout) [
May 18 14:18:49 dhcp2-a lrmd: [2929]: info: RA output:
(lease-parser_5:stop:stdout)   OK  ]
May 18 14:18:49 dhcp2-a lrmd: [2929]: info: RA output:
(lease-parser_5:stop:stdout)
May 18 14:18:49 dhcp2-a crmd: [2932]: info: process_lrm_event: LRM
operation lease-parser_5_stop_0 (call=80, rc=0) complete
May 18 14:18:50 dhcp2-a crmd: [2932]: info: do_lrm_rsc_op: Performing
op=dhcpd_4_stop_0 key=26:179:68fc3118-d505-4de6-b318-d3a9832f1869)
May 18 14:18:50 dhcp2-a lrmd: [2929]: info: rsc:dhcpd_4: stop
May 18 14:18:50 dhcp2-a lrmd: [3271]: WARN: For LSB init script, no
additional parameters are needed.
May 18 14:18:50 dhcp2-a crmd: [2932]: info: process_lrm_event: LRM
operation dhcpd_4_monitor_120000 (call=77, rc=-2) Cancelled
May 18 14:18:50 dhcp2-a lrmd: [2929]: info: RA output:
(dhcpd_4:stop:stdout) Shutting down dhcpd:
May 18 14:18:54 dhcp2-a lrmd: [2929]: info: RA output:
(dhcpd_4:stop:stdout) [FAILED]
May 18 14:18:54 dhcp2-a lrmd: [2929]: info: RA output: (dhcpd_4:stop:stdout)
May 18 14:18:54 dhcp2-a crmd: [2932]: ERROR: process_lrm_event: LRM
operation dhcpd_4_stop_0 (call=81, rc=1) Error unknown error
May 18 14:20:33 dhcp2-a cib: [2928]: info: cib_stats: Processed 12
operations (1666.00us average, 0% utilization) in the last 10min
May 18 14:21:47 dhcp2-a lrmd: [2929]: WARN: named:monitor process (PID
4062) timed out (try 1).  Killing with signal SIGTERM (15).
May 18 14:21:47 dhcp2-a lrmd: [2929]: WARN: operation monitor[75] on
lsb::named::named for client 2932, its parameters:
CRM_meta_interval=[120000] CRM_meta_start_delay=[0]
CRM_meta_role=[Started]
CRM_meta_id=[a5004e78-2241-4546-8906-02a054b48edf]
CRM_meta_timeout=[60000] crm_feature_set=[2.0]
CRM_meta_disabled=[false] CRM_meta_name=[monitor] : pid [4062] timed
out
May 18 14:21:47 dhcp2-a crmd: [2932]: ERROR: process_lrm_event: LRM
operation named_monitor_120000 (75) Timed Out (timeout=60000ms)
May 18 14:24:47 dhcp2-a lrmd: [2929]: WARN: named:monitor process (PID
5201) timed out (try 1).  Killing with signal SIGTERM (15).
May 18 14:24:47 dhcp2-a lrmd: [2929]: WARN: operation monitor[75] on
lsb::named::named for client 2932, its parameters:
CRM_meta_interval=[120000] CRM_meta_start_delay=[0]
CRM_meta_role=[Started] C
RM_meta_id=[a5004e78-2241-4546-8906-02a054b48edf]
CRM_meta_timeout=[60000] crm_feature_set=[2.0]
CRM_meta_disabled=[false] CRM_meta_name=[monitor] : pid [5201] timed
outMay 18 14:24:47 dhcp2-a crmd: [2932]: ERROR: process_lrm_event: LRM
operation named_monitor_120000 (75) Timed Out (timeout=60000ms)
May 18 14:27:47 dhcp2-a lrmd: [2929]: WARN: named:monitor process (PID
6400) timed out (try 1).  Killing with signal SIGTERM (15).
May 18 14:27:47 dhcp2-a lrmd: [2929]: WARN: operation monitor[75] on
lsb::named::named for client 2932, its parameters:
CRM_meta_interval=[120000] CRM_meta_start_delay=[0]
CRM_meta_role=[Started] C
RM_meta_id=[a5004e78-2241-4546-8906-02a054b48edf]
CRM_meta_timeout=[60000] crm_feature_set=[2.0]
CRM_meta_disabled=[false] CRM_meta_name=[monitor] : pid [6400] timed
out
May 18 14:27:47 dhcp2-a crmd: [2932]: ERROR: process_lrm_event: LRM
operation named_monitor_120000 (75) Timed Out (timeout=60000ms)May 18
14:30:33 dhcp2-a cib: [2928]: info: cib_stats: Processed 6 operations
(5000.00us average, 0% utilization) in the last 10min

For the time being, I've taken the monitoring function out of the
named process.  The only thing I can think of that may have caused
this is I changed iptables and restarted it.  Any insights?  Should I
consider moving to the 2.99.x branch?  Thanks for any help.
-- 
Jiann-Ming Su
"I have to decide between two equally frightening options.
 If I wanted to do that, I'd vote." --Duckman
"The system's broke, Hank.  The election baby has peed in
the bath water.  You got to throw 'em both out."  --Dale Gribble
"Those who vote decide nothing.
Those who count the votes decide everything.”  --Joseph Stalin
_______________________________________________
Linux-HA mailing list
[email protected]
http://lists.linux-ha.org/mailman/listinfo/linux-ha
See also: http://linux-ha.org/ReportingProblems

Reply via email to