[Pacemaker] mysql cluster resource agent failed to start

Fri Aug 17 12:02:28 UTC 2012

Hi,

thank you for your quick answer.
Here are the relevant parts of the corosync logfile, I think:

Aug 17 13:45:40 hydra2 crmd: [26828]: info: do_state_transition: State transition S_POLICY_ENGINE -> S_TRANSITION_ENGINE [ input=I_PE_SUCCESS cause=C_IPC_MESSAGE origin=handle_response ]
Aug 17 13:45:40 hydra2 crmd: [26828]: info: unpack_graph: Unpacked transition 852: 4 actions in 4 synapses
Aug 17 13:45:40 hydra2 crmd: [26828]: info: do_te_invoke: Processing graph 852 (ref=pe_calc-dc-1345203940-1109) derived from /var/lib/pengine/pe-input-453.bz2
Aug 17 13:45:40 hydra2 crmd: [26828]: info: te_pseudo_action: Pseudo action 421 fired and confirmed
Aug 17 13:45:40 hydra2 crmd: [26828]: info: te_rsc_command: Initiating action 62: stop mysqltest03-db_stop_0 on hydra2 (local)
Aug 17 13:45:40 hydra2 crmd: [26828]: info: do_lrm_rsc_op: Performing key=62:852:0:eb13866d-3a8f-4d87-bc81-82e893dc72d6 op=mysqltest03-db_stop_0 )
Aug 17 13:45:40 hydra2 lrmd: [26825]: info: rsc:mysqltest03-db stop[246] (pid 12138)
Aug 17 13:45:40 hydra2 pengine: [26827]: notice: process_pe_message: Transition 852: PEngine Input stored in: /var/lib/pengine/pe-input-453.bz2
Aug 17 13:45:41 hydra2 lrmd: [26825]: info: operation stop[246] on mysqltest03-db for client 26828: pid 12138 exited with return code 0
Aug 17 13:45:41 hydra2 crmd: [26828]: info: process_lrm_event: LRM operation mysqltest03-db_stop_0 (call=246, rc=0, cib-update=1325, confirmed=true) ok
Aug 17 13:45:41 hydra2 crmd: [26828]: info: match_graph_event: Action mysqltest03-db_stop_0 (62) confirmed on hydra2 (rc=0)
Aug 17 13:45:41 hydra2 crmd: [26828]: info: te_pseudo_action: Pseudo action 422 fired and confirmed
Aug 17 13:45:41 hydra2 crmd: [26828]: info: te_pseudo_action: Pseudo action 90 fired and confirmed
Aug 17 13:45:41 hydra2 crmd: [26828]: info: run_graph: ====================================================
Aug 17 13:45:41 hydra2 crmd: [26828]: notice: run_graph: Transition 852 (Complete=4, Pending=0, Fired=0, Skipped=0, Incomplete=0, Source=/var/lib/pengine/pe-input-453.bz2): Complete
Aug 17 13:45:41 hydra2 crmd: [26828]: info: te_graph_trigger: Transition 852 is now complete
Aug 17 13:45:41 hydra2 crmd: [26828]: info: notify_crmd: Transition 852 status: done - <null>
Aug 17 13:45:41 hydra2 crmd: [26828]: info: do_state_transition: State transition S_TRANSITION_ENGINE -> S_IDLE [ input=I_TE_SUCCESS cause=C_FSA_INTERNAL origin=notify_crmd ]
Aug 17 13:45:41 hydra2 crmd: [26828]: info: do_state_transition: Starting PEngine Recheck Timer
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: - <cib admin_epoch="0" epoch="244" num_updates="118" >
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: -   <configuration >
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: -     <resources >
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: -       <group id="mysqltest03" >
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: -         <primitive id="mysqltest03-db" >
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: -           <meta_attributes id="mysqltest03-db-meta_attributes" >
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: -             <nvpair value="started" id="mysqltest03-db-meta_attributes-target-role" />
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: -           </meta_attributes>
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: -         </primitive>
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: -       </group>
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: -     </resources>
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: -   </configuration>
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: - </cib>
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: + <cib epoch="245" num_updates="1" admin_epoch="0" validate-with="pacemaker-1.2" crm_feature_set="3.0.5" update-origin="hydra2" update-client="cibadmin" cib-last-written="Fri Aug 17 13:45:22 2012" have-quorum="0" dc-uuid="hydra2" >
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: +   <configuration >
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: +     <resources >
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: +       <group id="mysqltest03" >
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: +         <primitive class="ocf" id="mysqltest03-db" provider="heartbeat" type="mysql" >
Aug 17 13:47:11 hydra2 crmd: [26828]: info: abort_transition_graph: te_update_diff:124 - Triggered transition abort (complete=1, tag=diff, id=(null), magic=NA, cib=0.245.1) : Non-status change
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: +           <meta_attributes id="mysqltest03-db-meta_attributes" >
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: +             <nvpair id="mysqltest03-db-meta_attributes-target-role" name="target-role" value="Started" />
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: +           </meta_attributes>
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: +         </primitive>
Aug 17 13:47:11 hydra2 crmd: [26828]: info: do_state_transition: State transition S_IDLE -> S_POLICY_ENGINE [ input=I_PE_CALC cause=C_FSA_INTERNAL origin=abort_transition_graph ]
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: +       </group>
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: +     </resources>
Aug 17 13:47:11 hydra2 crmd: [26828]: info: do_state_transition: All 1 cluster nodes are eligible to run resources.
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: +   </configuration>
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib:diff: + </cib>
Aug 17 13:47:11 hydra2 cib: [26824]: info: cib_process_request: Operation complete: op cib_replace for section resources (origin=local/cibadmin/2, version=0.245.1): ok (rc=0)
Aug 17 13:47:11 hydra2 crmd: [26828]: info: do_pe_invoke: Query 1326: Requesting the current CIB: S_POLICY_ENGINE
Aug 17 13:47:12 hydra2 crmd: [26828]: info: do_pe_invoke_callback: Invoking the PE: query=1326, ref=pe_calc-dc-1345204031-1111, seq=40, quorate=0
Aug 17 13:47:12 hydra2 pengine: [26827]: notice: unpack_config: On loss of CCM Quorum: Ignore

As an additional information, I forgot to say, that I stopped corosync on the other node to prevent the resource groups from doing an failover.

Thanks for your help,

Josef

-----Ursprüngliche Nachricht-----
Von: Michael Schwartzkopff [mailto:misch at clusterbau.com] 
Gesendet: Freitag, 17. August 2012 13:40
An: The Pacemaker cluster resource manager
Betreff: Re: [Pacemaker] mysql cluster resource agent failed to start

> Hello everybody,
> 
> I have here several MySQL failover clusters with pacemaker and 
> corosync at Ubuntu 10.04 LTS running. After a problem with a crashed 
> cluster cib, I decided to reinstall one of the cluster with Ubuntu 
> 12.04 LTS. I always have used the packages of the distribution for the 
> cluster. The new Installation have the same configuration of the cluster as the old one.
> Now everything seemed to work well. Only the mysql resource agent have 
> now a strange behaviour. If I startet a resource group, pacemaker 
> started the mysql database and after one or two seconds he sends a 
> shutdown signal to the mysql agent. I have tried to start the mysql 
> resource agent at the bash with the same command options as pacemaker 
> would do. If I do this, the mysql db starts witout problems. In the 
> log files of the mysql db, I can see that it is a graceful shutdown. 
> Unfortunately are on this cluster
> 16 service groups. If I put the cluster in debug mode, the whole 
> server is getting very slow. So I had to abort the debug mode, to keep 
> the databases running.
> 
> This is the configuration of the mysql resource agent:
> primitive mysqltest03-db ocf:heartbeat:mysql \
>         params binary="/srv/mysql-server/releases/mysql/bin/mysqld"
> config="/srv/mysql/mysqltest03/admin/etc/my.cnf" user="mysql"
> group="mysql" datadir="/srv/mysql/mysqltest03/data"
> log="/srv/mysql/mysqltest03/admin/log/mysqld.log"
> pid="/srv/mysql/mysqltest03/admin/run/mysqld.pid"
> socket="/srv/mysql/mysqltest03/admin/run/mysqld.sock" test_passwd="xxx"
> test_user="xxx" test_table="mysql.user"
> additional_parameters="--bind-address=xx.xx.xx.xx" \ op start interval="0"
> timeout="120s" \
>         op stop interval="0" timeout="120s" \
>         op monitor interval="30s" timeout="60s" \
>         meta is-managed="true" target-role="started"
> 
> 
> Is anybody here, who can give me a hint, why pacemaker always sends a 
> stop signal after one second?
> 
> Thanks,
> 
> Josef

the truth is in the logs. Read the logs to find out why pacemaker does behave like this or paste the relevant parts of the logs somewhere and send the link to this list. So we could help you.

Greetings,

--
Dr. Michael Schwartzkopff
Guardinistr. 63
81375 München

Tel: (0163) 172 50 98