diff --git a/daemons/controld/controld_fsa.c b/daemons/controld/controld_fsa.c index 6a08c86c9c..6fa5111d7e 100644 --- a/daemons/controld/controld_fsa.c +++ b/daemons/controld/controld_fsa.c @@ -1,743 +1,743 @@ /* * Copyright 2004-2022 the Pacemaker project contributors * * The version control history for this file may have further details. * * This source code is licensed under the GNU General Public License version 2 * or later (GPLv2+) WITHOUT ANY WARRANTY. */ #include #include #include #include // uint64_t #include #include #include #include #include #include #include #include #include #include //! Triggers an FSA invocation static crm_trigger_t *fsa_trigger = NULL; #define DOT_PREFIX "actions:trace: " #define do_dot_log(fmt, args...) crm_trace( fmt, ##args) static void do_state_transition(enum crmd_fsa_state cur_state, enum crmd_fsa_state next_state, fsa_data_t *msg_data); void s_crmd_fsa_actions(fsa_data_t * fsa_data); void log_fsa_input(fsa_data_t * stored_msg); void init_dotfile(void); void init_dotfile(void) { do_dot_log(DOT_PREFIX "digraph \"g\" {"); do_dot_log(DOT_PREFIX " size = \"30,30\""); do_dot_log(DOT_PREFIX " graph ["); do_dot_log(DOT_PREFIX " fontsize = \"12\""); do_dot_log(DOT_PREFIX " fontname = \"Times-Roman\""); do_dot_log(DOT_PREFIX " fontcolor = \"black\""); do_dot_log(DOT_PREFIX " bb = \"0,0,398.922306,478.927856\""); do_dot_log(DOT_PREFIX " color = \"black\""); do_dot_log(DOT_PREFIX " ]"); do_dot_log(DOT_PREFIX " node ["); do_dot_log(DOT_PREFIX " fontsize = \"12\""); do_dot_log(DOT_PREFIX " fontname = \"Times-Roman\""); do_dot_log(DOT_PREFIX " fontcolor = \"black\""); do_dot_log(DOT_PREFIX " shape = \"ellipse\""); do_dot_log(DOT_PREFIX " color = \"black\""); do_dot_log(DOT_PREFIX " ]"); do_dot_log(DOT_PREFIX " edge ["); do_dot_log(DOT_PREFIX " fontsize = \"12\""); do_dot_log(DOT_PREFIX " fontname = \"Times-Roman\""); do_dot_log(DOT_PREFIX " fontcolor = \"black\""); do_dot_log(DOT_PREFIX " color = \"black\""); do_dot_log(DOT_PREFIX " ]"); do_dot_log(DOT_PREFIX "// special nodes"); do_dot_log(DOT_PREFIX " \"S_PENDING\" "); do_dot_log(DOT_PREFIX " ["); do_dot_log(DOT_PREFIX " color = \"blue\""); do_dot_log(DOT_PREFIX " fontcolor = \"blue\""); do_dot_log(DOT_PREFIX " ]"); do_dot_log(DOT_PREFIX " \"S_TERMINATE\" "); do_dot_log(DOT_PREFIX " ["); do_dot_log(DOT_PREFIX " color = \"red\""); do_dot_log(DOT_PREFIX " fontcolor = \"red\""); do_dot_log(DOT_PREFIX " ]"); do_dot_log(DOT_PREFIX "// DC only nodes"); do_dot_log(DOT_PREFIX " \"S_INTEGRATION\" [ fontcolor = \"green\" ]"); do_dot_log(DOT_PREFIX " \"S_POLICY_ENGINE\" [ fontcolor = \"green\" ]"); do_dot_log(DOT_PREFIX " \"S_TRANSITION_ENGINE\" [ fontcolor = \"green\" ]"); do_dot_log(DOT_PREFIX " \"S_RELEASE_DC\" [ fontcolor = \"green\" ]"); do_dot_log(DOT_PREFIX " \"S_IDLE\" [ fontcolor = \"green\" ]"); } static void do_fsa_action(fsa_data_t * fsa_data, long long an_action, void (*function) (long long action, enum crmd_fsa_cause cause, enum crmd_fsa_state cur_state, enum crmd_fsa_input cur_input, fsa_data_t * msg_data)) { controld_clear_fsa_action_flags(an_action); crm_trace(DOT_PREFIX "\t// %s", fsa_action2string(an_action)); function(an_action, fsa_data->fsa_cause, controld_globals.fsa_state, fsa_data->fsa_input, fsa_data); } static const uint64_t startup_actions = A_STARTUP | A_CIB_START | A_LRM_CONNECT | A_HA_CONNECT | A_READCONFIG | A_STARTED | A_CL_JOIN_QUERY; // A_LOG, A_WARN, A_ERROR void do_log(long long action, enum crmd_fsa_cause cause, enum crmd_fsa_state cur_state, enum crmd_fsa_input current_input, fsa_data_t *msg_data) { unsigned log_type = LOG_TRACE; if (action & A_LOG) { log_type = LOG_INFO; } else if (action & A_WARN) { log_type = LOG_WARNING; } else if (action & A_ERROR) { log_type = LOG_ERR; } do_crm_log(log_type, "Input %s received in state %s from %s", fsa_input2string(msg_data->fsa_input), fsa_state2string(cur_state), msg_data->origin); if (msg_data->data_type == fsa_dt_ha_msg) { ha_msg_input_t *input = fsa_typed_data(msg_data->data_type); crm_log_xml_debug(input->msg, __func__); } else if (msg_data->data_type == fsa_dt_xml) { xmlNode *input = fsa_typed_data(msg_data->data_type); crm_log_xml_debug(input, __func__); } else if (msg_data->data_type == fsa_dt_lrm) { lrmd_event_data_t *input = fsa_typed_data(msg_data->data_type); do_crm_log(log_type, "Resource %s: Call ID %d returned %d (%d)." " New status if rc=0: %s", input->rsc_id, input->call_id, input->rc, input->op_status, (char *)input->user_data); } } /*! * \internal * \brief Initialize the FSA trigger */ void controld_init_fsa_trigger(void) { fsa_trigger = mainloop_add_trigger(G_PRIORITY_HIGH, crm_fsa_trigger, NULL); } /*! * \internal * \brief Destroy the FSA trigger */ void controld_destroy_fsa_trigger(void) { // This basically will not work, since mainloop has a reference to it mainloop_destroy_trigger(fsa_trigger); fsa_trigger = NULL; } /*! * \internal * \brief Trigger an FSA invocation * * \param[in] fn Calling function name * \param[in] line Line number where call occurred */ void controld_trigger_fsa_as(const char *fn, int line) { if (fsa_trigger != NULL) { crm_trace("%s:%d - Triggered FSA invocation", fn, line); mainloop_set_trigger(fsa_trigger); } } enum crmd_fsa_state s_crmd_fsa(enum crmd_fsa_cause cause) { controld_globals_t *globals = &controld_globals; fsa_data_t *fsa_data = NULL; uint64_t register_copy = controld_globals.fsa_input_register; uint64_t new_actions = A_NOTHING; enum crmd_fsa_state last_state; crm_trace("FSA invoked with Cause: %s\tState: %s", fsa_cause2string(cause), fsa_state2string(globals->fsa_state)); fsa_dump_actions(controld_globals.fsa_actions, "Initial"); controld_clear_global_flags(controld_fsa_is_stalled); if ((controld_globals.fsa_message_queue == NULL) && (controld_globals.fsa_actions != A_NOTHING)) { /* fake the first message so we can get into the loop */ fsa_data = calloc(1, sizeof(fsa_data_t)); fsa_data->fsa_input = I_NULL; fsa_data->fsa_cause = C_FSA_INTERNAL; fsa_data->origin = __func__; fsa_data->data_type = fsa_dt_none; controld_globals.fsa_message_queue = g_list_append(controld_globals.fsa_message_queue, fsa_data); fsa_data = NULL; } while ((controld_globals.fsa_message_queue != NULL) && !pcmk_is_set(controld_globals.flags, controld_fsa_is_stalled)) { crm_trace("Checking messages (%d remaining)", g_list_length(controld_globals.fsa_message_queue)); fsa_data = get_message(); if(fsa_data == NULL) { continue; } log_fsa_input(fsa_data); /* add any actions back to the queue */ controld_set_fsa_action_flags(fsa_data->actions); fsa_dump_actions(fsa_data->actions, "Restored actions"); /* get the next batch of actions */ new_actions = controld_fsa_get_action(fsa_data->fsa_input, globals->fsa_state); controld_set_fsa_action_flags(new_actions); fsa_dump_actions(new_actions, "New actions"); if (fsa_data->fsa_input != I_NULL && fsa_data->fsa_input != I_ROUTER) { crm_debug("Processing %s: [ state=%s cause=%s origin=%s ]", fsa_input2string(fsa_data->fsa_input), fsa_state2string(globals->fsa_state), fsa_cause2string(fsa_data->fsa_cause), fsa_data->origin); } /* logging : *before* the state is changed */ if (pcmk_is_set(controld_globals.fsa_actions, A_ERROR)) { do_fsa_action(fsa_data, A_ERROR, do_log); } if (pcmk_is_set(controld_globals.fsa_actions, A_WARN)) { do_fsa_action(fsa_data, A_WARN, do_log); } if (pcmk_is_set(controld_globals.fsa_actions, A_LOG)) { do_fsa_action(fsa_data, A_LOG, do_log); } /* update state variables */ last_state = globals->fsa_state; globals->fsa_state = controld_fsa_get_next_state(fsa_data->fsa_input, globals->fsa_state); /* * Remove certain actions during shutdown */ if ((globals->fsa_state == S_STOPPING) || pcmk_is_set(controld_globals.fsa_input_register, R_SHUTDOWN)) { controld_clear_fsa_action_flags(startup_actions); } /* * Hook for change of state. * Allows actions to be added or removed when entering a state */ if (last_state != globals->fsa_state) { do_state_transition(last_state, globals->fsa_state, fsa_data); } else { do_dot_log(DOT_PREFIX "\t// FSA input: State=%s \tCause=%s" " \tInput=%s \tOrigin=%s() \tid=%d", fsa_state2string(globals->fsa_state), fsa_cause2string(fsa_data->fsa_cause), fsa_input2string(fsa_data->fsa_input), fsa_data->origin, fsa_data->id); } /* start doing things... */ s_crmd_fsa_actions(fsa_data); delete_fsa_input(fsa_data); fsa_data = NULL; } if ((controld_globals.fsa_message_queue != NULL) || (controld_globals.fsa_actions != A_NOTHING) || pcmk_is_set(controld_globals.flags, controld_fsa_is_stalled)) { crm_debug("Exiting the FSA: queue=%d, fsa_actions=%#llx, stalled=%s", g_list_length(controld_globals.fsa_message_queue), (unsigned long long) controld_globals.fsa_actions, pcmk__btoa(pcmk_is_set(controld_globals.flags, controld_fsa_is_stalled))); } else { crm_trace("Exiting the FSA"); } /* cleanup inputs? */ if (register_copy != controld_globals.fsa_input_register) { uint64_t same = register_copy & controld_globals.fsa_input_register; fsa_dump_inputs(LOG_DEBUG, "Added", controld_globals.fsa_input_register ^ same); fsa_dump_inputs(LOG_DEBUG, "Removed", register_copy ^ same); } fsa_dump_actions(controld_globals.fsa_actions, "Remaining"); fsa_dump_queue(LOG_DEBUG); return globals->fsa_state; } void s_crmd_fsa_actions(fsa_data_t * fsa_data) { /* * Process actions in order of priority but do only one * action at a time to avoid complicating the ordering. */ CRM_CHECK(fsa_data != NULL, return); while ((controld_globals.fsa_actions != A_NOTHING) && !pcmk_is_set(controld_globals.flags, controld_fsa_is_stalled)) { /* regular action processing in order of action priority * * Make sure all actions that connect to required systems * are performed first */ if (pcmk_is_set(controld_globals.fsa_actions, A_ERROR)) { do_fsa_action(fsa_data, A_ERROR, do_log); } else if (pcmk_is_set(controld_globals.fsa_actions, A_WARN)) { do_fsa_action(fsa_data, A_WARN, do_log); } else if (pcmk_is_set(controld_globals.fsa_actions, A_LOG)) { do_fsa_action(fsa_data, A_LOG, do_log); /* get out of here NOW! before anything worse happens */ } else if (pcmk_is_set(controld_globals.fsa_actions, A_EXIT_1)) { do_fsa_action(fsa_data, A_EXIT_1, do_exit); /* sub-system restart */ } else if (pcmk_all_flags_set(controld_globals.fsa_actions, O_LRM_RECONNECT)) { do_fsa_action(fsa_data, O_LRM_RECONNECT, do_lrm_control); } else if (pcmk_all_flags_set(controld_globals.fsa_actions, O_CIB_RESTART)) { do_fsa_action(fsa_data, O_CIB_RESTART, do_cib_control); } else if (pcmk_all_flags_set(controld_globals.fsa_actions, O_PE_RESTART)) { do_fsa_action(fsa_data, O_PE_RESTART, do_pe_control); } else if (pcmk_all_flags_set(controld_globals.fsa_actions, O_TE_RESTART)) { do_fsa_action(fsa_data, O_TE_RESTART, do_te_control); /* essential start tasks */ } else if (pcmk_is_set(controld_globals.fsa_actions, A_STARTUP)) { do_fsa_action(fsa_data, A_STARTUP, do_startup); } else if (pcmk_is_set(controld_globals.fsa_actions, A_CIB_START)) { do_fsa_action(fsa_data, A_CIB_START, do_cib_control); } else if (pcmk_is_set(controld_globals.fsa_actions, A_HA_CONNECT)) { do_fsa_action(fsa_data, A_HA_CONNECT, do_ha_control); } else if (pcmk_is_set(controld_globals.fsa_actions, A_READCONFIG)) { do_fsa_action(fsa_data, A_READCONFIG, do_read_config); /* sub-system start/connect */ } else if (pcmk_is_set(controld_globals.fsa_actions, A_LRM_CONNECT)) { do_fsa_action(fsa_data, A_LRM_CONNECT, do_lrm_control); } else if (pcmk_is_set(controld_globals.fsa_actions, A_TE_START)) { do_fsa_action(fsa_data, A_TE_START, do_te_control); } else if (pcmk_is_set(controld_globals.fsa_actions, A_PE_START)) { do_fsa_action(fsa_data, A_PE_START, do_pe_control); /* Timers */ } else if (pcmk_is_set(controld_globals.fsa_actions, A_DC_TIMER_STOP)) { do_fsa_action(fsa_data, A_DC_TIMER_STOP, do_timer_control); } else if (pcmk_is_set(controld_globals.fsa_actions, A_INTEGRATE_TIMER_STOP)) { do_fsa_action(fsa_data, A_INTEGRATE_TIMER_STOP, do_timer_control); } else if (pcmk_is_set(controld_globals.fsa_actions, A_INTEGRATE_TIMER_START)) { do_fsa_action(fsa_data, A_INTEGRATE_TIMER_START, do_timer_control); } else if (pcmk_is_set(controld_globals.fsa_actions, A_FINALIZE_TIMER_STOP)) { do_fsa_action(fsa_data, A_FINALIZE_TIMER_STOP, do_timer_control); } else if (pcmk_is_set(controld_globals.fsa_actions, A_FINALIZE_TIMER_START)) { do_fsa_action(fsa_data, A_FINALIZE_TIMER_START, do_timer_control); /* * Highest priority actions */ } else if (pcmk_is_set(controld_globals.fsa_actions, A_MSG_ROUTE)) { do_fsa_action(fsa_data, A_MSG_ROUTE, do_msg_route); } else if (pcmk_is_set(controld_globals.fsa_actions, A_RECOVER)) { do_fsa_action(fsa_data, A_RECOVER, do_recover); } else if (pcmk_is_set(controld_globals.fsa_actions, A_CL_JOIN_RESULT)) { do_fsa_action(fsa_data, A_CL_JOIN_RESULT, do_cl_join_finalize_respond); } else if (pcmk_is_set(controld_globals.fsa_actions, A_CL_JOIN_REQUEST)) { do_fsa_action(fsa_data, A_CL_JOIN_REQUEST, do_cl_join_offer_respond); } else if (pcmk_is_set(controld_globals.fsa_actions, A_SHUTDOWN_REQ)) { do_fsa_action(fsa_data, A_SHUTDOWN_REQ, do_shutdown_req); } else if (pcmk_is_set(controld_globals.fsa_actions, A_ELECTION_VOTE)) { do_fsa_action(fsa_data, A_ELECTION_VOTE, do_election_vote); } else if (pcmk_is_set(controld_globals.fsa_actions, A_ELECTION_COUNT)) { do_fsa_action(fsa_data, A_ELECTION_COUNT, do_election_count_vote); } else if (pcmk_is_set(controld_globals.fsa_actions, A_LRM_EVENT)) { do_fsa_action(fsa_data, A_LRM_EVENT, do_lrm_event); /* * High priority actions */ } else if (pcmk_is_set(controld_globals.fsa_actions, A_STARTED)) { do_fsa_action(fsa_data, A_STARTED, do_started); } else if (pcmk_is_set(controld_globals.fsa_actions, A_CL_JOIN_QUERY)) { do_fsa_action(fsa_data, A_CL_JOIN_QUERY, do_cl_join_query); } else if (pcmk_is_set(controld_globals.fsa_actions, A_DC_TIMER_START)) { do_fsa_action(fsa_data, A_DC_TIMER_START, do_timer_control); /* * Medium priority actions * - Membership */ } else if (pcmk_is_set(controld_globals.fsa_actions, A_DC_TAKEOVER)) { do_fsa_action(fsa_data, A_DC_TAKEOVER, do_dc_takeover); } else if (pcmk_is_set(controld_globals.fsa_actions, A_DC_RELEASE)) { do_fsa_action(fsa_data, A_DC_RELEASE, do_dc_release); } else if (pcmk_is_set(controld_globals.fsa_actions, A_DC_JOIN_FINAL)) { do_fsa_action(fsa_data, A_DC_JOIN_FINAL, do_dc_join_final); } else if (pcmk_is_set(controld_globals.fsa_actions, A_ELECTION_CHECK)) { do_fsa_action(fsa_data, A_ELECTION_CHECK, do_election_check); } else if (pcmk_is_set(controld_globals.fsa_actions, A_ELECTION_START)) { do_fsa_action(fsa_data, A_ELECTION_START, do_election_vote); } else if (pcmk_is_set(controld_globals.fsa_actions, A_DC_JOIN_OFFER_ALL)) { do_fsa_action(fsa_data, A_DC_JOIN_OFFER_ALL, do_dc_join_offer_all); } else if (pcmk_is_set(controld_globals.fsa_actions, A_DC_JOIN_OFFER_ONE)) { do_fsa_action(fsa_data, A_DC_JOIN_OFFER_ONE, do_dc_join_offer_one); } else if (pcmk_is_set(controld_globals.fsa_actions, A_DC_JOIN_PROCESS_REQ)) { do_fsa_action(fsa_data, A_DC_JOIN_PROCESS_REQ, do_dc_join_filter_offer); } else if (pcmk_is_set(controld_globals.fsa_actions, A_DC_JOIN_PROCESS_ACK)) { do_fsa_action(fsa_data, A_DC_JOIN_PROCESS_ACK, do_dc_join_ack); } else if (pcmk_is_set(controld_globals.fsa_actions, A_DC_JOIN_FINALIZE)) { do_fsa_action(fsa_data, A_DC_JOIN_FINALIZE, do_dc_join_finalize); } else if (pcmk_is_set(controld_globals.fsa_actions, A_CL_JOIN_ANNOUNCE)) { do_fsa_action(fsa_data, A_CL_JOIN_ANNOUNCE, do_cl_join_announce); /* * Low(er) priority actions * Make sure the CIB is always updated before invoking the * scheduler, and the scheduler before the transition engine. */ } else if (pcmk_is_set(controld_globals.fsa_actions, A_TE_HALT)) { do_fsa_action(fsa_data, A_TE_HALT, do_te_invoke); } else if (pcmk_is_set(controld_globals.fsa_actions, A_TE_CANCEL)) { do_fsa_action(fsa_data, A_TE_CANCEL, do_te_invoke); } else if (pcmk_is_set(controld_globals.fsa_actions, A_LRM_INVOKE)) { do_fsa_action(fsa_data, A_LRM_INVOKE, do_lrm_invoke); } else if (pcmk_is_set(controld_globals.fsa_actions, A_PE_INVOKE)) { do_fsa_action(fsa_data, A_PE_INVOKE, do_pe_invoke); } else if (pcmk_is_set(controld_globals.fsa_actions, A_TE_INVOKE)) { do_fsa_action(fsa_data, A_TE_INVOKE, do_te_invoke); /* Shutdown actions */ } else if (pcmk_is_set(controld_globals.fsa_actions, A_DC_RELEASED)) { do_fsa_action(fsa_data, A_DC_RELEASED, do_dc_release); } else if (pcmk_is_set(controld_globals.fsa_actions, A_PE_STOP)) { do_fsa_action(fsa_data, A_PE_STOP, do_pe_control); } else if (pcmk_is_set(controld_globals.fsa_actions, A_TE_STOP)) { do_fsa_action(fsa_data, A_TE_STOP, do_te_control); } else if (pcmk_is_set(controld_globals.fsa_actions, A_SHUTDOWN)) { do_fsa_action(fsa_data, A_SHUTDOWN, do_shutdown); } else if (pcmk_is_set(controld_globals.fsa_actions, A_LRM_DISCONNECT)) { do_fsa_action(fsa_data, A_LRM_DISCONNECT, do_lrm_control); } else if (pcmk_is_set(controld_globals.fsa_actions, A_HA_DISCONNECT)) { do_fsa_action(fsa_data, A_HA_DISCONNECT, do_ha_control); } else if (pcmk_is_set(controld_globals.fsa_actions, A_CIB_STOP)) { do_fsa_action(fsa_data, A_CIB_STOP, do_cib_control); } else if (pcmk_is_set(controld_globals.fsa_actions, A_STOP)) { do_fsa_action(fsa_data, A_STOP, do_stop); /* exit gracefully */ } else if (pcmk_is_set(controld_globals.fsa_actions, A_EXIT_0)) { do_fsa_action(fsa_data, A_EXIT_0, do_exit); /* Error checking and reporting */ } else { crm_err("Action %s not supported "CRM_XS" %#llx", fsa_action2string(controld_globals.fsa_actions), (unsigned long long) controld_globals.fsa_actions); register_fsa_error_adv(C_FSA_INTERNAL, I_ERROR, fsa_data, NULL, __func__); } } } void log_fsa_input(fsa_data_t * stored_msg) { CRM_ASSERT(stored_msg); crm_trace("Processing queued input %d", stored_msg->id); if (stored_msg->fsa_cause == C_LRM_OP_CALLBACK) { crm_trace("FSA processing LRM callback from %s", stored_msg->origin); } else if (stored_msg->data == NULL) { crm_trace("FSA processing input from %s", stored_msg->origin); } else { ha_msg_input_t *ha_input = fsa_typed_data_adv(stored_msg, fsa_dt_ha_msg, __func__); crm_trace("FSA processing XML message from %s", stored_msg->origin); crm_log_xml_trace(ha_input->xml, "FSA message data"); } } static void check_join_counts(fsa_data_t *msg_data) { int count; guint npeers; count = crmd_join_phase_count(crm_join_finalized); if (count > 0) { crm_err("%d cluster node%s failed to confirm join", count, pcmk__plural_s(count)); crmd_join_phase_log(LOG_NOTICE); return; } npeers = crm_active_peers(); count = crmd_join_phase_count(crm_join_confirmed); if (count == npeers) { if (npeers == 1) { crm_debug("Sole active cluster node is fully joined"); } else { crm_debug("All %d active cluster nodes are fully joined", count); } } else if (count > npeers) { crm_err("New election needed because more nodes confirmed join " "than are in membership (%d > %u)", count, npeers); register_fsa_input(C_FSA_INTERNAL, I_ELECTION, NULL); } else if (controld_globals.membership_id != crm_peer_seq) { crm_info("New join needed because membership changed (%llu -> %llu)", controld_globals.membership_id, crm_peer_seq); register_fsa_input_before(C_FSA_INTERNAL, I_NODE_JOIN, NULL); } else { crm_warn("Only %d of %u active cluster nodes fully joined " "(%d did not respond to offer)", count, npeers, crmd_join_phase_count(crm_join_welcomed)); } } static void do_state_transition(enum crmd_fsa_state cur_state, enum crmd_fsa_state next_state, fsa_data_t *msg_data) { int level = LOG_INFO; int count = 0; gboolean clear_recovery_bit = TRUE; #if 0 uint64_t original_fsa_actions = controld_globals.fsa_actions; #endif enum crmd_fsa_cause cause = msg_data->fsa_cause; enum crmd_fsa_input current_input = msg_data->fsa_input; const char *state_from = fsa_state2string(cur_state); const char *state_to = fsa_state2string(next_state); const char *input = fsa_input2string(current_input); CRM_LOG_ASSERT(cur_state != next_state); do_dot_log(DOT_PREFIX "\t%s -> %s [ label=%s cause=%s origin=%s ]", state_from, state_to, input, fsa_cause2string(cause), msg_data->origin); if (cur_state == S_IDLE || next_state == S_IDLE) { level = LOG_NOTICE; } else if (cur_state == S_NOT_DC || next_state == S_NOT_DC) { level = LOG_NOTICE; } else if (cur_state == S_ELECTION) { level = LOG_NOTICE; } else if (cur_state == S_STARTING) { level = LOG_NOTICE; } else if (next_state == S_RECOVERY) { level = LOG_WARNING; } do_crm_log(level, "State transition %s -> %s " CRM_XS " input=%s cause=%s origin=%s", state_from, state_to, input, fsa_cause2string(cause), msg_data->origin); if (next_state != S_ELECTION && cur_state != S_RELEASE_DC) { controld_stop_current_election_timeout(); } #if 0 if ((controld_globals.fsa_input_register & R_SHUTDOWN)) { controld_set_fsa_action_flags(A_DC_TIMER_STOP); } #endif if (next_state == S_INTEGRATION) { controld_set_fsa_action_flags(A_INTEGRATE_TIMER_START); } else { controld_set_fsa_action_flags(A_INTEGRATE_TIMER_STOP); } if (next_state == S_FINALIZE_JOIN) { controld_set_fsa_action_flags(A_FINALIZE_TIMER_START); } else { controld_set_fsa_action_flags(A_FINALIZE_TIMER_STOP); } if (next_state != S_PENDING) { controld_set_fsa_action_flags(A_DC_TIMER_STOP); } if (next_state != S_IDLE) { - controld_stop_timer(recheck_timer); + controld_stop_recheck_timer(); } if (cur_state == S_FINALIZE_JOIN && next_state == S_POLICY_ENGINE) { populate_cib_nodes(node_update_quick|node_update_all, __func__); } switch (next_state) { case S_PENDING: { cib_t *cib_conn = controld_globals.cib_conn; cib_conn->cmds->set_secondary(cib_conn, cib_scope_local); } update_dc(NULL); break; case S_ELECTION: update_dc(NULL); break; case S_NOT_DC: election_timer->counter = 0; purge_stonith_cleanup(); if (pcmk_is_set(controld_globals.fsa_input_register, R_SHUTDOWN)) { crm_info("(Re)Issuing shutdown request now" " that we have a new DC"); controld_set_fsa_action_flags(A_SHUTDOWN_REQ); } CRM_LOG_ASSERT(controld_globals.dc_name != NULL); if (controld_globals.dc_name == NULL) { crm_err("Reached S_NOT_DC without a DC" " being recorded"); } break; case S_RECOVERY: clear_recovery_bit = FALSE; break; case S_FINALIZE_JOIN: CRM_LOG_ASSERT(AM_I_DC); if (cause == C_TIMER_POPPED) { crm_warn("Progressed to state %s after %s", fsa_state2string(next_state), fsa_cause2string(cause)); } count = crmd_join_phase_count(crm_join_welcomed); if (count > 0) { crm_warn("%d cluster node%s failed to respond to join offer", count, pcmk__plural_s(count)); crmd_join_phase_log(LOG_NOTICE); } else { crm_debug("All cluster nodes (%d) responded to join offer", crmd_join_phase_count(crm_join_integrated)); } break; case S_POLICY_ENGINE: election_timer->counter = 0; CRM_LOG_ASSERT(AM_I_DC); if (cause == C_TIMER_POPPED) { crm_info("Progressed to state %s after %s", fsa_state2string(next_state), fsa_cause2string(cause)); } check_join_counts(msg_data); break; case S_STOPPING: case S_TERMINATE: /* possibly redundant */ controld_set_fsa_input_flags(R_SHUTDOWN); break; case S_IDLE: CRM_LOG_ASSERT(AM_I_DC); if (pcmk_is_set(controld_globals.fsa_input_register, R_SHUTDOWN)) { crm_info("(Re)Issuing shutdown request now" " that we are the DC"); controld_set_fsa_action_flags(A_SHUTDOWN_REQ); } controld_start_recheck_timer(); break; default: break; } if (clear_recovery_bit && next_state != S_PENDING) { controld_clear_fsa_action_flags(A_RECOVER); } else if (clear_recovery_bit == FALSE) { controld_set_fsa_action_flags(A_RECOVER); } #if 0 if (original_fsa_actions != controld_globals.fsa_actions) { fsa_dump_actions(original_fsa_actions ^ controld_globals.fsa_actions, "New actions"); } #endif } diff --git a/daemons/controld/controld_timers.c b/daemons/controld/controld_timers.c index 9a19afedce..e78d435822 100644 --- a/daemons/controld/controld_timers.c +++ b/daemons/controld/controld_timers.c @@ -1,402 +1,418 @@ /* * Copyright 2004-2022 the Pacemaker project contributors * * The version control history for this file may have further details. * * This source code is licensed under the GNU General Public License version 2 * or later (GPLv2+) WITHOUT ANY WARRANTY. */ #include #include #include #include #include #include //! Wait before retrying a failed cib or executor connection static fsa_timer_t *wait_timer = NULL; -// Periodically re-run scheduler (for date_spec evaluation and as a failsafe) -fsa_timer_t *recheck_timer = NULL; +//! Periodically re-run scheduler (for date_spec evaluation and as a failsafe) +static fsa_timer_t *recheck_timer = NULL; // Wait at start-up, or after an election, for DC to make contact fsa_timer_t *election_timer = NULL; // Delay start of new transition with expectation something else might happen fsa_timer_t *transition_timer = NULL; // join-integration-timeout fsa_timer_t *integration_timer = NULL; // join-finalization-timeout fsa_timer_t *finalization_timer = NULL; // Wait for DC to stop all resources and give us the all-clear to shut down fsa_timer_t *shutdown_escalation_timer = NULL; //! Cluster recheck interval (from configuration) static guint recheck_interval_ms = 0; /* A_DC_TIMER_STOP, A_DC_TIMER_START, * A_FINALIZE_TIMER_STOP, A_FINALIZE_TIMER_START * A_INTEGRATE_TIMER_STOP, A_INTEGRATE_TIMER_START */ void do_timer_control(long long action, enum crmd_fsa_cause cause, enum crmd_fsa_state cur_state, enum crmd_fsa_input current_input, fsa_data_t * msg_data) { gboolean timer_op_ok = TRUE; if (action & A_DC_TIMER_STOP) { timer_op_ok = controld_stop_timer(election_timer); } else if (action & A_FINALIZE_TIMER_STOP) { timer_op_ok = controld_stop_timer(finalization_timer); } else if (action & A_INTEGRATE_TIMER_STOP) { timer_op_ok = controld_stop_timer(integration_timer); } /* don't start a timer that wasn't already running */ if (action & A_DC_TIMER_START && timer_op_ok) { controld_start_timer(election_timer); if (AM_I_DC) { /* there can be only one */ register_fsa_input(cause, I_ELECTION, NULL); } } else if (action & A_FINALIZE_TIMER_START) { controld_start_timer(finalization_timer); } else if (action & A_INTEGRATE_TIMER_START) { controld_start_timer(integration_timer); } } static const char * get_timer_desc(fsa_timer_t * timer) { if (timer == election_timer) { return "Election Trigger"; } else if (timer == shutdown_escalation_timer) { return "Shutdown Escalation"; } else if (timer == integration_timer) { return "Integration Timer"; } else if (timer == finalization_timer) { return "Finalization Timer"; } else if (timer == transition_timer) { return "New Transition Timer"; } else if (timer == wait_timer) { return "Wait Timer"; } else if (timer == recheck_timer) { return "Cluster Recheck Timer"; } return "Unknown Timer"; } static gboolean crm_timer_popped(gpointer data) { fsa_timer_t *timer = (fsa_timer_t *) data; if (timer->log_error) { crm_err("%s just popped in state %s! " CRM_XS " input=%s time=%ums", get_timer_desc(timer), fsa_state2string(controld_globals.fsa_state), fsa_input2string(timer->fsa_input), timer->period_ms); } else { crm_info("%s just popped " CRM_XS " input=%s time=%ums", get_timer_desc(timer), fsa_input2string(timer->fsa_input), timer->period_ms); timer->counter++; } if ((timer == election_timer) && (election_timer->counter > 5)) { crm_notice("We appear to be in an election loop, something may be wrong"); crm_write_blackbox(0, NULL); election_timer->counter = 0; } controld_stop_timer(timer); // Make timer _not_ go off again if (timer->fsa_input == I_INTEGRATED) { crm_info("Welcomed: %d, Integrated: %d", crmd_join_phase_count(crm_join_welcomed), crmd_join_phase_count(crm_join_integrated)); if (crmd_join_phase_count(crm_join_welcomed) == 0) { // If we don't even have ourselves, start again register_fsa_error_adv(C_FSA_INTERNAL, I_ELECTION, NULL, NULL, __func__); } else { register_fsa_input_before(C_TIMER_POPPED, timer->fsa_input, NULL); } } else if ((timer == recheck_timer) && (controld_globals.fsa_state != S_IDLE)) { crm_debug("Discarding %s event in state: %s", fsa_input2string(timer->fsa_input), fsa_state2string(controld_globals.fsa_state)); } else if ((timer == finalization_timer) && (controld_globals.fsa_state != S_FINALIZE_JOIN)) { crm_debug("Discarding %s event in state: %s", fsa_input2string(timer->fsa_input), fsa_state2string(controld_globals.fsa_state)); } else if (timer->fsa_input != I_NULL) { register_fsa_input(C_TIMER_POPPED, timer->fsa_input, NULL); } controld_trigger_fsa(); return TRUE; } bool controld_init_fsa_timers(void) { transition_timer = calloc(1, sizeof(fsa_timer_t)); if (transition_timer == NULL) { return FALSE; } integration_timer = calloc(1, sizeof(fsa_timer_t)); if (integration_timer == NULL) { return FALSE; } finalization_timer = calloc(1, sizeof(fsa_timer_t)); if (finalization_timer == NULL) { return FALSE; } election_timer = calloc(1, sizeof(fsa_timer_t)); if (election_timer == NULL) { return FALSE; } shutdown_escalation_timer = calloc(1, sizeof(fsa_timer_t)); if (shutdown_escalation_timer == NULL) { return FALSE; } wait_timer = calloc(1, sizeof(fsa_timer_t)); if (wait_timer == NULL) { return FALSE; } recheck_timer = calloc(1, sizeof(fsa_timer_t)); if (recheck_timer == NULL) { return FALSE; } election_timer->source_id = 0; election_timer->period_ms = 0; election_timer->fsa_input = I_DC_TIMEOUT; election_timer->callback = crm_timer_popped; election_timer->log_error = FALSE; transition_timer->source_id = 0; transition_timer->period_ms = 0; transition_timer->fsa_input = I_PE_CALC; transition_timer->callback = crm_timer_popped; transition_timer->log_error = FALSE; integration_timer->source_id = 0; integration_timer->period_ms = 0; integration_timer->fsa_input = I_INTEGRATED; integration_timer->callback = crm_timer_popped; integration_timer->log_error = TRUE; finalization_timer->source_id = 0; finalization_timer->period_ms = 0; finalization_timer->fsa_input = I_FINALIZED; finalization_timer->callback = crm_timer_popped; finalization_timer->log_error = FALSE; /* We can't use I_FINALIZED here, because that creates a bug in the join * process where a joining node can be stuck in S_PENDING while we think it * is in S_NOT_DC. This created an infinite transition loop in which we * continually send probes which the node NACKs because it's pending. * * If we have nodes where the cluster layer is active but the controller is * not, we can avoid this causing an election/join loop, in the integration * phase. */ finalization_timer->fsa_input = I_ELECTION; shutdown_escalation_timer->source_id = 0; shutdown_escalation_timer->period_ms = 0; shutdown_escalation_timer->fsa_input = I_STOP; shutdown_escalation_timer->callback = crm_timer_popped; shutdown_escalation_timer->log_error = TRUE; wait_timer->source_id = 0; wait_timer->period_ms = 2000; wait_timer->fsa_input = I_NULL; wait_timer->callback = crm_timer_popped; wait_timer->log_error = FALSE; recheck_timer->source_id = 0; recheck_timer->period_ms = 0; recheck_timer->fsa_input = I_PE_CALC; recheck_timer->callback = crm_timer_popped; recheck_timer->log_error = FALSE; return TRUE; } /*! * \internal * \brief Configure timers based on the CIB * * \param[in,out] options Name/value pairs for configured options */ void controld_configure_fsa_timers(GHashTable *options) { const char *value = NULL; // Election timer value = g_hash_table_lookup(options, XML_CONFIG_ATTR_DC_DEADTIME); election_timer->period_ms = crm_parse_interval_spec(value); // Integration timer value = g_hash_table_lookup(options, "join-integration-timeout"); integration_timer->period_ms = crm_parse_interval_spec(value); // Finalization timer value = g_hash_table_lookup(options, "join-finalization-timeout"); finalization_timer->period_ms = crm_parse_interval_spec(value); // Shutdown escalation timer value = g_hash_table_lookup(options, XML_CONFIG_ATTR_FORCE_QUIT); shutdown_escalation_timer->period_ms = crm_parse_interval_spec(value); crm_debug("Shutdown escalation occurs if DC has not responded to request " "in %ums", shutdown_escalation_timer->period_ms); // Transition timer value = g_hash_table_lookup(options, "transition-delay"); transition_timer->period_ms = crm_parse_interval_spec(value); // Recheck interval value = g_hash_table_lookup(options, XML_CONFIG_ATTR_RECHECK); recheck_interval_ms = crm_parse_interval_spec(value); crm_debug("Re-run scheduler after %dms of inactivity", recheck_interval_ms); } void controld_free_fsa_timers(void) { controld_stop_timer(transition_timer); controld_stop_timer(integration_timer); controld_stop_timer(finalization_timer); controld_stop_timer(election_timer); controld_stop_timer(shutdown_escalation_timer); controld_stop_timer(wait_timer); controld_stop_timer(recheck_timer); free(transition_timer); transition_timer = NULL; free(integration_timer); integration_timer = NULL; free(finalization_timer); finalization_timer = NULL; free(election_timer); election_timer = NULL; free(shutdown_escalation_timer); shutdown_escalation_timer = NULL; free(wait_timer); wait_timer = NULL; free(recheck_timer); recheck_timer = NULL; } gboolean is_timer_started(fsa_timer_t * timer) { return (timer->period_ms > 0) && (timer->source_id != 0); } void controld_start_timer(fsa_timer_t *timer) { if (timer->source_id == 0 && timer->period_ms > 0) { timer->source_id = g_timeout_add(timer->period_ms, timer->callback, (void *)timer); CRM_ASSERT(timer->source_id != 0); crm_debug("Started %s (inject %s if pops after %ums, source=%d)", get_timer_desc(timer), fsa_input2string(timer->fsa_input), timer->period_ms, timer->source_id); } else { crm_debug("%s already running (inject %s if pops after %ums, source=%d)", get_timer_desc(timer), fsa_input2string(timer->fsa_input), timer->period_ms, timer->source_id); } } +/*! + * \internal + * \brief Start the recheck timer + */ void controld_start_recheck_timer(void) { // Default to recheck interval configured in CIB (if any) guint period_ms = recheck_interval_ms; // If scheduler supplied a "recheck by" time, check whether that's sooner if (controld_globals.transition_graph->recheck_by > 0) { time_t diff_seconds = controld_globals.transition_graph->recheck_by - time(NULL); if (diff_seconds < 1) { // We're already past the desired time period_ms = 500; } else { period_ms = (guint) diff_seconds * 1000; } // Use "recheck by" only if it's sooner than interval from CIB if (period_ms > recheck_interval_ms) { period_ms = recheck_interval_ms; } } if (period_ms > 0) { recheck_timer->period_ms = period_ms; controld_start_timer(recheck_timer); } } /*! * \internal * \brief Start the wait timer */ void controld_start_wait_timer(void) { controld_start_timer(wait_timer); } -gboolean +bool controld_stop_timer(fsa_timer_t *timer) { - CRM_CHECK(timer != NULL, return FALSE); + CRM_CHECK(timer != NULL, return false); if (timer->source_id != 0) { crm_trace("Stopping %s (would inject %s if popped after %ums, src=%d)", get_timer_desc(timer), fsa_input2string(timer->fsa_input), timer->period_ms, timer->source_id); g_source_remove(timer->source_id); timer->source_id = 0; } else { crm_trace("%s already stopped (would inject %s if popped after %ums)", get_timer_desc(timer), fsa_input2string(timer->fsa_input), timer->period_ms); - return FALSE; + return false; } - return TRUE; + return true; +} + +/*! + * \internal + * \brief Stop the recheck timer + * + * \return true if the recheck timer was running, or false otherwise + */ +bool +controld_stop_recheck_timer(void) +{ + return controld_stop_timer(recheck_timer); } diff --git a/daemons/controld/controld_timers.h b/daemons/controld/controld_timers.h index f7be48a24c..1d6fbb3835 100644 --- a/daemons/controld/controld_timers.h +++ b/daemons/controld/controld_timers.h @@ -1,45 +1,45 @@ /* * Copyright 2004-2022 the Pacemaker project contributors * * The version control history for this file may have further details. * * This source code is licensed under the GNU Lesser General Public License * version 2.1 or later (LGPLv2.1+) WITHOUT ANY WARRANTY. */ #ifndef CONTROLD_TIMERS__H # define CONTROLD_TIMERS__H # include // bool # include // gboolean, gpointer, guint # include // crmd_fsa_input typedef struct fsa_timer_s { guint source_id; // Timer source ID guint period_ms; // Timer period enum crmd_fsa_input fsa_input; // Input to register if timer pops gboolean (*callback) (gpointer data); // What do if timer pops bool log_error; // Timer popping indicates error int counter; // For detecting loops } fsa_timer_t; extern fsa_timer_t *election_timer; extern fsa_timer_t *shutdown_escalation_timer; extern fsa_timer_t *transition_timer; extern fsa_timer_t *integration_timer; extern fsa_timer_t *finalization_timer; -extern fsa_timer_t *recheck_timer; bool controld_init_fsa_timers(void); void controld_free_fsa_timers(void); void controld_configure_fsa_timers(GHashTable *options); -gboolean controld_stop_timer(fsa_timer_t *timer); +bool controld_stop_timer(fsa_timer_t *timer); +bool controld_stop_recheck_timer(void); void controld_start_timer(fsa_timer_t *timer); void controld_start_recheck_timer(void); void controld_start_wait_timer(void); gboolean is_timer_started(fsa_timer_t *timer); #endif