From 33b3b7e7004e3ec5501c32a2217ec32775a5a487 Mon Sep 17 00:00:00 2001 From: Ken Gaillot Date: Mon, 24 Apr 2017 10:38:50 -0500 Subject: [PATCH 1/6] Refactor: libcib: functionize destroying op callback table reduces code duplication --- lib/cib/cib_client.c | 29 ++++++++++++----------------- 1 file changed, 12 insertions(+), 17 deletions(-) diff --git a/lib/cib/cib_client.c b/lib/cib/cib_client.c index 5ded943..0f53330 100644 --- a/lib/cib/cib_client.c +++ b/lib/cib/cib_client.c @@ -206,6 +206,15 @@ cib_destroy_op_callback(gpointer data) free(blob); } +static void +destroy_op_callback_table() +{ + if (cib_op_callback_table != NULL) { + g_hash_table_destroy(cib_op_callback_table); + cib_op_callback_table = NULL; + } +} + char * get_shadow_file(const char *suffix) { @@ -348,14 +357,7 @@ cib_new_variant(void) new_cib = calloc(1, sizeof(cib_t)); - if (cib_op_callback_table != NULL) { - g_hash_table_destroy(cib_op_callback_table); - cib_op_callback_table = NULL; - } - if (cib_op_callback_table == NULL) { - cib_op_callback_table = g_hash_table_new_full(g_direct_hash, g_direct_equal, - NULL, cib_destroy_op_callback); - } + remove_cib_op_callback(0, TRUE); /* remove all */ new_cib->call_id = 1; new_cib->variant = cib_undefined; @@ -419,10 +421,7 @@ cib_delete(cib_t * cib) free(client); } - if(cib_op_callback_table) { - g_hash_table_destroy(cib_op_callback_table); - cib_op_callback_table = NULL; - } + destroy_op_callback_table(); if(cib) { cib->cmds->free(cib); @@ -639,13 +638,9 @@ void remove_cib_op_callback(int call_id, gboolean all_callbacks) { if (all_callbacks) { - if (cib_op_callback_table != NULL) { - g_hash_table_destroy(cib_op_callback_table); - } - + destroy_op_callback_table(); cib_op_callback_table = g_hash_table_new_full(g_direct_hash, g_direct_equal, NULL, cib_destroy_op_callback); - } else { g_hash_table_remove(cib_op_callback_table, GINT_TO_POINTER(call_id)); } -- 1.8.3.1 From 360cf350722f9646581e47b4d73d971aa81e6cec Mon Sep 17 00:00:00 2001 From: Ken Gaillot Date: Fri, 21 Apr 2017 11:31:01 -0500 Subject: [PATCH 2/6] Low: crmd: avoid use-after-free when disconnecting from CIB crmd_exit() freed the CIB connection, then drained the mainloop. However, the mainloop could call functions (such as do_cib_control() or cib_native_destroy()) that would use the connection object. This would lead to a segfault, though the harm was minimal, since the crmd was already exiting at this point. Also log a notice comparable to what's done for the crmd's other disconnects. --- crmd/cib.c | 17 ++++++----------- crmd/control.c | 10 ++++++++-- include/crm/cib.h | 1 + lib/cib/cib_client.c | 35 ++++++++++++++++++++++++----------- 4 files changed, 39 insertions(+), 24 deletions(-) diff --git a/crmd/cib.c b/crmd/cib.c index 40fed4a..41f4f3d 100644 --- a/crmd/cib.c +++ b/crmd/cib.c @@ -159,19 +159,16 @@ do_cib_replaced(const char *event, xmlNode * msg) register_fsa_input(C_FSA_INTERNAL, I_ELECTION, NULL); } -/* A_CIB_STOP, A_CIB_START, A_CIB_RESTART, */ +/* A_CIB_STOP, A_CIB_START, O_CIB_RESTART */ void do_cib_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) { - struct crm_subsystem_s *this_subsys = cib_subsystem; + CRM_ASSERT(fsa_cib_conn != NULL); - long long stop_actions = A_CIB_STOP; - long long start_actions = A_CIB_START; - - if (action & stop_actions) { + if (action & A_CIB_STOP) { if (fsa_cib_conn->state != cib_disconnected && last_resource_update != 0) { crm_info("Waiting for resource update %d to complete", last_resource_update); @@ -181,7 +178,6 @@ do_cib_control(long long action, crm_info("Disconnecting CIB"); clear_bit(fsa_input_register, R_CIB_CONNECTED); - CRM_ASSERT(fsa_cib_conn != NULL); fsa_cib_conn->cmds->del_notify_callback(fsa_cib_conn, T_CIB_DIFF_NOTIFY, do_cib_updated); @@ -189,15 +185,14 @@ do_cib_control(long long action, fsa_cib_conn->cmds->set_slave(fsa_cib_conn, cib_scope_local); fsa_cib_conn->cmds->signoff(fsa_cib_conn); } + crm_notice("Disconnected from the CIB"); } - if (action & start_actions) { + if (action & A_CIB_START) { int rc = pcmk_ok; - CRM_ASSERT(fsa_cib_conn != NULL); - if (cur_state == S_STOPPING) { - crm_err("Ignoring request to start %s after shutdown", this_subsys->name); + crm_err("Ignoring request to start the CIB after shutdown"); return; } diff --git a/crmd/control.c b/crmd/control.c index af9c2c2..a9c0b73 100644 --- a/crmd/control.c +++ b/crmd/control.c @@ -355,8 +355,11 @@ crmd_exit(int rc) election_fini(fsa_election); fsa_election = NULL; - cib_delete(fsa_cib_conn); - fsa_cib_conn = NULL; + /* Tear down the CIB connection, but don't free it yet -- it could be used + * when we drain the mainloop later. + */ + cib_free_callbacks(fsa_cib_conn); + fsa_cib_conn->cmds->signoff(fsa_cib_conn); verify_stopped(fsa_state, LOG_WARNING); clear_bit(fsa_input_register, R_LRM_CONNECTED); @@ -485,6 +488,9 @@ crmd_exit(int rc) mainloop_destroy_signal(SIGCHLD); } + cib_delete(fsa_cib_conn); + fsa_cib_conn = NULL; + /* Graceful */ return rc; } diff --git a/include/crm/cib.h b/include/crm/cib.h index a1246d1..ec52602 100644 --- a/include/crm/cib.h +++ b/include/crm/cib.h @@ -172,6 +172,7 @@ cib_t *cib_new_no_shadow(void); char *get_shadow_file(const char *name); cib_t *cib_shadow_new(const char *name); +void cib_free_callbacks(cib_t *cib); void cib_delete(cib_t * cib); void cib_dump_pending_callbacks(void); diff --git a/lib/cib/cib_client.c b/lib/cib/cib_client.c index 0f53330..907bb5a 100644 --- a/lib/cib/cib_client.c +++ b/lib/cib/cib_client.c @@ -406,24 +406,37 @@ cib_new_variant(void) return new_cib; } +/*! + * \brief Free all callbacks for a CIB connection + * + * \param[in] cib CIB connection to clean up + */ void -cib_delete(cib_t * cib) +cib_free_callbacks(cib_t *cib) { - GList *list = NULL; - if(cib) { - list = cib->notify_list; - } + if (cib) { + GList *list = cib->notify_list; - while (list != NULL) { - cib_notify_client_t *client = g_list_nth_data(list, 0); + while (list != NULL) { + cib_notify_client_t *client = g_list_nth_data(list, 0); - list = g_list_remove(list, client); - free(client); + list = g_list_remove(list, client); + free(client); + } } - destroy_op_callback_table(); +} - if(cib) { +/*! + * \brief Free all memory used by CIB connection + * + * \param[in] cib CIB connection to delete + */ +void +cib_delete(cib_t *cib) +{ + cib_free_callbacks(cib); + if (cib) { cib->cmds->free(cib); } } -- 1.8.3.1 From a6383a30d3258856efef1c067790faa78d1a5787 Mon Sep 17 00:00:00 2001 From: Ken Gaillot Date: Fri, 21 Apr 2017 11:33:53 -0500 Subject: [PATCH 3/6] Low: crmd: don't destroy election structure twice didn't cause any harm, but unnecessary --- crmd/control.c | 1 - 1 file changed, 1 deletion(-) diff --git a/crmd/control.c b/crmd/control.c index a9c0b73..5d91b1d 100644 --- a/crmd/control.c +++ b/crmd/control.c @@ -388,7 +388,6 @@ crmd_exit(int rc) free(integration_timer); integration_timer = NULL; free(finalization_timer); finalization_timer = NULL; free(election_trigger); election_trigger = NULL; - election_fini(fsa_election); free(shutdown_escalation_timer); shutdown_escalation_timer = NULL; free(wait_timer); wait_timer = NULL; free(recheck_timer); recheck_timer = NULL; -- 1.8.3.1 From 8183dbf57bc92a79b54c7e56942e4e3bda36654f Mon Sep 17 00:00:00 2001 From: Ken Gaillot Date: Mon, 1 May 2017 14:58:58 -0500 Subject: [PATCH 4/6] Log: libcib: downgrade ACL status message to trace gets logged 1-3 times for every CIB op --- lib/cib/cib_utils.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/cib/cib_utils.c b/lib/cib/cib_utils.c index 1908401..ab48f16 100644 --- a/lib/cib/cib_utils.c +++ b/lib/cib/cib_utils.c @@ -282,7 +282,7 @@ cib_acl_enabled(xmlNode *xml, const char *user) g_hash_table_destroy(options); } - crm_debug("CIB ACL is %s", rc ? "enabled" : "disabled"); + crm_trace("CIB ACL is %s", rc ? "enabled" : "disabled"); #endif return rc; } -- 1.8.3.1 From f1f9bf7ceb3737ed4d731669c2e5744a9e234a04 Mon Sep 17 00:00:00 2001 From: Ken Gaillot Date: Mon, 1 May 2017 17:06:03 -0500 Subject: [PATCH 5/6] Low: libcrmcommon: don't delay next flush by more than 5 seconds If an IPC client falls behind on processing incoming events, we set a progressive delay between queue flushes. However, at the maximum backlog of 500 events, this would be 51 seconds. Cap this delay at 5 seconds. --- lib/common/ipc.c | 22 +++++++++++++++++++--- 1 file changed, 19 insertions(+), 3 deletions(-) diff --git a/lib/common/ipc.c b/lib/common/ipc.c index 2949837..c9e3da2 100644 --- a/lib/common/ipc.c +++ b/lib/common/ipc.c @@ -463,12 +463,28 @@ crm_ipcs_flush_events_cb(gpointer data) return FALSE; } +/*! + * \internal + * \brief Add progressive delay before next event queue flush + * + * \param[in,out] c Client connection to add delay to + * \param[in] queue_len Current event queue length + */ +static inline void +delay_next_flush(crm_client_t *c, unsigned int queue_len) +{ + /* Delay a maximum of 5 seconds */ + guint delay = (queue_len < 40)? (1000 + 100 * queue_len) : 5000; + + c->event_timer = g_timeout_add(delay, crm_ipcs_flush_events_cb, c); +} + ssize_t crm_ipcs_flush_events(crm_client_t * c) { - int sent = 0; ssize_t rc = 0; - int queue_len = 0; + unsigned int sent = 0; + unsigned int queue_len = 0; if (c == NULL) { return pcmk_ok; @@ -523,8 +539,8 @@ crm_ipcs_flush_events(crm_client_t * c) qb_ipcs_disconnect(c->ipcs); return rc; } + delay_next_flush(c, queue_len); - c->event_timer = g_timeout_add(1000 + 100 * queue_len, crm_ipcs_flush_events_cb, c); } return rc; -- 1.8.3.1 From 5d94da7af947810ca4b12dc1d9dce18a7d638f73 Mon Sep 17 00:00:00 2001 From: Ken Gaillot Date: Mon, 1 May 2017 17:39:02 -0500 Subject: [PATCH 6/6] Fix: libcrmcommon: avoid evicting IPC client if messages spike briefly Before, an IP server would evict a client if its event queue grew to 500 messages. Now, we avoid evicting if the backlog is new (a quick spike of many messages that immediately crosses the threshold). --- include/crm/common/ipcs.h | 5 ++++- lib/common/ipc.c | 41 ++++++++++++++++++++++++++++++++--------- 2 files changed, 36 insertions(+), 10 deletions(-) diff --git a/include/crm/common/ipcs.h b/include/crm/common/ipcs.h index 2fec931..ba1ccef 100644 --- a/include/crm/common/ipcs.h +++ b/include/crm/common/ipcs.h @@ -73,6 +73,8 @@ struct crm_client_s { char *name; char *user; + /* Provided for server use (not used by library) */ + /* @TODO merge options, flags, and kind (reserving lower bits for server) */ long long options; int request_id; @@ -80,7 +82,7 @@ struct crm_client_s { void *userdata; int event_timer; - GList *event_queue; + GList *event_queue; /* @TODO use GQueue instead */ /* Depending on the value of kind, only some of the following * will be populated/valid @@ -91,6 +93,7 @@ struct crm_client_s { struct crm_remote_s *remote; /* TCP/TLS */ + unsigned int backlog_len; /* IPC queue length after last flush */ }; extern GHashTable *client_connections; diff --git a/lib/common/ipc.c b/lib/common/ipc.c index c9e3da2..d32e373 100644 --- a/lib/common/ipc.c +++ b/lib/common/ipc.c @@ -37,6 +37,9 @@ #define PCMK_IPC_VERSION 1 +/* Evict clients whose event queue grows this large */ +#define PCMK_IPC_MAX_QUEUE 500 + struct crm_ipc_response_header { struct qb_ipc_response_header qb; uint32_t size_uncompressed; @@ -523,24 +526,44 @@ crm_ipcs_flush_events(crm_client_t * c) } queue_len -= sent; - if (sent > 0 || c->event_queue) { + if (sent > 0 || queue_len) { crm_trace("Sent %d events (%d remaining) for %p[%d]: %s (%lld)", sent, queue_len, c->ipcs, c->pid, pcmk_strerror(rc < 0 ? rc : 0), (long long) rc); } - if (c->event_queue) { - if (queue_len % 100 == 0 && queue_len > 99) { - crm_warn("Event queue for %p[%d] has grown to %d", c->ipcs, c->pid, queue_len); + if (queue_len) { + /* We want to allow clients to briefly fall behind on processing + * incoming messages, but drop completely unresponsive clients so the + * connection doesn't consume resources indefinitely. + * + * @TODO It is possible that the queue could reasonably grow large in a + * short time. An example is a reprobe of hundreds of resources on many + * nodes resulting in a surge of CIB replies to the crmd. We could + * possibly give cluster daemons a higher threshold here, and/or prevent + * such a surge by throttling LRM history writes in the crmd. + */ - } else if (queue_len > 500) { - crm_err("Evicting slow client %p[%d]: event queue reached %d entries", - c->ipcs, c->pid, queue_len); - qb_ipcs_disconnect(c->ipcs); - return rc; + if (queue_len > PCMK_IPC_MAX_QUEUE) { + if ((c->backlog_len <= 1) || (queue_len < c->backlog_len)) { + /* Don't evict for a new or shrinking backlog */ + crm_warn("Client with process ID %u has a backlog of %u messages " + CRM_XS " %p", c->pid, queue_len, c->ipcs); + } else { + crm_err("Evicting client with process ID %u due to backlog of %u messages " + CRM_XS " %p", c->pid, queue_len, c->ipcs); + c->backlog_len = 0; + qb_ipcs_disconnect(c->ipcs); + return rc; + } } + + c->backlog_len = queue_len; delay_next_flush(c, queue_len); + } else { + /* Event queue is empty, there is no backlog */ + c->backlog_len = 0; } return rc; -- 1.8.3.1