Log: daemons: trace incoming IPC when parsing it

Previously, some callers of pcmk__client_data2xml() trace-logged the resulting
XML, and some didn't. Moving the log into the function itself reduces
duplication and ensures the trace is always done (at the minor cost of not
being able to trace just one daemon's incoming IPC).

Also remove an unused argument from the function.

daemons/attrd/pacemaker-attrd.c

@@ -250,7 +250,7 @@ attrd_ipc_dispatch(qb_ipcs_connection_t * c, void *data, size_t size)
         crm_debug("No IPC data from PID %d", pcmk__client_pid(c));
         return 0;
     }
-    xml = pcmk__client_data2xml(client, data, size, &id, &flags);
+    xml = pcmk__client_data2xml(client, data, &id, &flags);
     if (xml == NULL) {
         crm_debug("Unrecognizable IPC data from PID %d", pcmk__client_pid(c));
         return 0;
@@ -261,8 +261,6 @@ attrd_ipc_dispatch(qb_ipcs_connection_t * c, void *data, size_t size)
     crm_acl_get_set_user(xml, F_ATTRD_USER, client->user);
 #endif
 
-    crm_log_xml_trace(xml, __FUNCTION__);
-
     op = crm_element_value(xml, F_ATTRD_TASK);
 
     if (client->name == NULL) {

daemons/based/based_callbacks.c

@@ -207,8 +207,7 @@ cib_common_callback(qb_ipcs_connection_t * c, void *data, size_t size, gboolean
     uint32_t flags = 0;
     int call_options = 0;
     pcmk__client_t *cib_client = pcmk__find_client(c);
-    xmlNode *op_request = pcmk__client_data2xml(cib_client, data, size, &id,
-                                                &flags);
+    xmlNode *op_request = pcmk__client_data2xml(cib_client, data, &id, &flags);
 
     if (op_request) {
         crm_element_value_int(op_request, F_CIB_CALLOPTS, &call_options);
@@ -261,8 +260,6 @@ cib_common_callback(qb_ipcs_connection_t * c, void *data, size_t size, gboolean
     crm_acl_get_set_user(op_request, F_CIB_USER, cib_client->user);
 #endif
 
-    crm_log_xml_trace(op_request, "Client[inbound]");
-
     cib_common_callback_worker(id, flags, op_request, cib_client, privileged);
     free_xml(op_request);
 

daemons/controld/controld_control.c

@@ -373,7 +373,7 @@ dispatch_controller_ipc(qb_ipcs_connection_t * c, void *data, size_t size)
     uint32_t flags = 0;
     pcmk__client_t *client = pcmk__find_client(c);
 
-    xmlNode *msg = pcmk__client_data2xml(client, data, size, &id, &flags);
+    xmlNode *msg = pcmk__client_data2xml(client, data, &id, &flags);
 
     pcmk__ipc_send_ack(client, id, flags, "ack");
     if (msg == NULL) {
@@ -385,7 +385,6 @@ dispatch_controller_ipc(qb_ipcs_connection_t * c, void *data, size_t size)
     crm_acl_get_set_user(msg, F_CRM_USER, client->user);
 #endif
 
-    crm_log_xml_trace(msg, "controller[inbound]");
     crm_xml_add(msg, F_CRM_SYS_FROM, client->id);
     if (controld_authorize_ipc_message(msg, client, NULL)) {
         crm_trace("Processing IPC message from %s", pcmk__client_name(client));

daemons/execd/execd_commands.c

@@ -1841,8 +1841,7 @@ process_lrmd_message(pcmk__client_t *client, uint32_t id, xmlNode *request)
     } else {
         rc = -EOPNOTSUPP;
         do_reply = 1;
-        crm_err("Unknown %s from %s", op, client->name);
-        crm_log_xml_warn(request, "UnknownOp");
+        crm_err("Unknown IPC request '%s' from %s", op, client->name);
     }
 
     crm_debug("Processed %s operation from %s: rc=%d, reply=%d, notify=%d",

daemons/execd/pacemaker-execd.c

@@ -111,7 +111,7 @@ lrmd_ipc_dispatch(qb_ipcs_connection_t * c, void *data, size_t size)
     uint32_t id = 0;
     uint32_t flags = 0;
     pcmk__client_t *client = pcmk__find_client(c);
-    xmlNode *request = pcmk__client_data2xml(client, data, size, &id, &flags);
+    xmlNode *request = pcmk__client_data2xml(client, data, &id, &flags);
 
     CRM_CHECK(client != NULL, crm_err("Invalid client");
               return FALSE);

daemons/execd/remoted_proxy.c

@@ -234,7 +234,7 @@ ipc_proxy_dispatch(qb_ipcs_connection_t * c, void *data, size_t size)
      * This function is receiving a request from connection
      * 1 and forwarding it to connection 2.
      */
-    request = pcmk__client_data2xml(client, data, size, &id, &flags);
+    request = pcmk__client_data2xml(client, data, &id, &flags);
 
     if (!request) {
         return 0;

daemons/fenced/fenced_commands.c

@@ -2641,8 +2641,8 @@ handle_request(pcmk__client_t *client, uint32_t id, uint32_t flags,
         return pcmk_ok;
 
     } else {
-        crm_err("Unknown %s from %s", op, client ? client->name : remote_peer);
-        crm_log_xml_warn(request, "UnknownOp");
+        crm_err("Unknown IPC request %s from %s",
+                op, (client? client->name : remote_peer));
     }
 
   done:

daemons/fenced/pacemaker-fenced.c

@@ -90,7 +90,7 @@ st_ipc_dispatch(qb_ipcs_connection_t * qbc, void *data, size_t size)
         return 0;
     }
 
-    request = pcmk__client_data2xml(c, data, size, &id, &flags);
+    request = pcmk__client_data2xml(c, data, &id, &flags);
     if (request == NULL) {
         pcmk__ipc_send_ack(c, id, flags, "nack");
         return 0;
@@ -133,7 +133,6 @@ st_ipc_dispatch(qb_ipcs_connection_t * qbc, void *data, size_t size)
     crm_xml_add(request, F_STONITH_CLIENTNAME, pcmk__client_name(c));
     crm_xml_add(request, F_STONITH_CLIENTNODE, stonith_our_uname);
 
-    crm_log_xml_trace(request, "Client[inbound]");
     stonith_command(c, id, flags, request, NULL);
 
     free_xml(request);

daemons/pacemakerd/pacemakerd.c

@@ -557,7 +557,7 @@ pcmk_ipc_dispatch(qb_ipcs_connection_t * qbc, void *data, size_t size)
     uint32_t flags = 0;
     const char *task = NULL;
     pcmk__client_t *c = pcmk__find_client(qbc);
-    xmlNode *msg = pcmk__client_data2xml(c, data, size, &id, &flags);
+    xmlNode *msg = pcmk__client_data2xml(c, data, &id, &flags);
 
     pcmk__ipc_send_ack(c, id, flags, "ack");
     if (msg == NULL) {

daemons/schedulerd/pacemaker-schedulerd.c

@@ -223,7 +223,7 @@ pe_ipc_dispatch(qb_ipcs_connection_t * qbc, void *data, size_t size)
     uint32_t id = 0;
     uint32_t flags = 0;
     pcmk__client_t *c = pcmk__find_client(qbc);
-    xmlNode *msg = pcmk__client_data2xml(c, data, size, &id, &flags);
+    xmlNode *msg = pcmk__client_data2xml(c, data, &id, &flags);
 
     pcmk__ipc_send_ack(c, id, flags, "ack");
     if (msg != NULL) {

include/crm/common/ipcs_internal.h

@@ -121,7 +121,7 @@ int pcmk__ipc_prepare_iov(uint32_t request, xmlNode *message,
 int pcmk__ipc_send_xml(pcmk__client_t *c, uint32_t request, xmlNode *message,
                        uint32_t flags);
 int pcmk__ipc_send_iov(pcmk__client_t *c, struct iovec *iov, uint32_t flags);
-xmlNode *pcmk__client_data2xml(pcmk__client_t *c, void *data, size_t size,
+xmlNode *pcmk__client_data2xml(pcmk__client_t *c, void *data,
                                uint32_t *id, uint32_t *flags);
 
 int pcmk__client_pid(qb_ipcs_connection_t *c);

lib/common/ipc.c

@@ -562,8 +562,19 @@ pcmk__client_pid(qb_ipcs_connection_t *c)
     return stats.client_pid;
 }
 
+/*!
+ * \internal
+ * \brief Retrieve message XML from data read from client IPC
+ *
+ * \param[in]  c       IPC client connection
+ * \param[in]  data    Data read from client connection
+ * \param[out] id      Where to store message ID from libqb header
+ * \param[out] flags   Where to store flags from libqb header
+ *
+ * \return Message XML on success, NULL otherwise
+ */
 xmlNode *
-pcmk__client_data2xml(pcmk__client_t *c, void *data, size_t size, uint32_t *id,
+pcmk__client_data2xml(pcmk__client_t *c, void *data, uint32_t *id,
                       uint32_t *flags)
 {
     xmlNode *xml = NULL;
@@ -613,8 +624,8 @@ pcmk__client_data2xml(pcmk__client_t *c, void *data, size_t size, uint32_t *id,
 
     CRM_ASSERT(text[header->size_uncompressed - 1] == 0);
 
-    crm_trace("Received %.200s", text);
     xml = string2xml(text);
+    crm_log_xml_trace(xml, "[IPC received]");
 
     free(uncompressed);
     return xml;

maint/mocked/based.c

@@ -182,8 +182,7 @@ mock_based_dispatch_command(qb_ipcs_connection_t *c, void *data, size_t size)
     uint32_t id = 0, flags = 0;
     int call_options = 0;
     pcmk__client_t *cib_client = pcmk__find_client(c);
-    xmlNode *op_request = pcmk__client_data2xml(cib_client, data, size, &id,
-                                                &flags);
+    xmlNode *op_request = pcmk__client_data2xml(cib_client, data, &id, &flags);
 
     crm_notice("Got connection %p", c);
     assert(op_request != NULL);