commit 3dd3d01c50d1a2430e1435a67b7e515816475bd2
Author: Klaus Wenninger <klaus.wenninger@aon.at>
Date:   Wed Nov 25 15:21:45 2015 +0100

    Fix CLBZ#5253: stonithd: Do not intermingle stdout & stderr coming from
        stonith-RAs so that metadata and host-list can be parsed properly.
        Modified fence_dummy to support action list and do some loggings
        on stderr to be able to test the fix in st_client.c.

Index: pacemaker/fencing/fence_dummy
===================================================================
--- pacemaker.orig/fencing/fence_dummy
+++ pacemaker/fencing/fence_dummy
@@ -71,7 +71,7 @@ all_opt = {
 	"action" : {
 		"getopt" : "o:",
 		"longopt" : "action",
-		"help" : "-o, --action=[action]          Action: status, reboot (default), off or on",
+		"help" : "-o, --action=[action]          Action: status, list, reboot (default), off or on",
 		"required" : "1",
 		"shortdesc" : "Fencing Action",
 		"default" : "reboot",
@@ -104,6 +104,13 @@ all_opt = {
 		"help" : "-U, --uuid                     UUID of the VM to fence.",
 		"required" : "0",
 		"shortdesc" : "The UUID of the virtual machine to fence.",
+		"order" : 1},
+	"mock_dynamic_hosts" : {
+		"getopt" : "H:",
+		"longopt" : "mock_dynamic_hosts",
+		"help" : "-H, --mock_dynamic_hosts=[hostlist]         List of hosts we can fence.",
+		"required" : "0",
+		"shortdesc" : "A list of hosts we can fence.",
 		"order" : 1}
 }
 
@@ -122,6 +129,7 @@ def show_docs(options, docs = None):
 		sys.exit(0)
 
 	if options.has_key("-o") and options["-o"].lower() == "metadata":
+		sys.stderr.write("asked for fence_dummy metadata\n")
 		metadata(device_opt, options, docs)
 		sys.exit(0)
 
@@ -201,7 +209,8 @@ def metadata(avail_opt, options, docs):
 
 	print "\t<action name=\"status\" />"
 	print "\t<action name=\"monitor\" />"
-	print "\t<action name=\"metadata\" />"	
+	print "\t<action name=\"metadata\" />"
+	print "\t<action name=\"list\" />"
 	print "</actions>"
 	print "</resource-agent>"
 
@@ -321,18 +330,26 @@ def main():
     # random sleep for testing
     if options.has_key("-f"):
         val = int(options["-f"])
-        sys.stderr.write("delay sleep for %d seconds" % val)
+        sys.stderr.write("delay sleep for %d seconds\n" % val)
         time.sleep(val)
 
     if options.has_key("-R"):
         val = int(options["-R"])
         ran = random.randint(1, val)
-        sys.stderr.write("random sleep for %d seconds" % ran)
+        sys.stderr.write("random sleep for %d seconds\n" % ran)
         time.sleep(ran)
 
     if options.has_key("-o") and (options["-o"] == "monitor"):
+        sys.stderr.write("fence_dummy monitor called\n")
         sys.exit(0)
     
+    if options.has_key("-o") and (options["-o"] == "list"):
+        sys.stderr.write("fence_dummy action (list) called\n")
+        if options.has_key("-H"):
+            print options["-H"]
+        else:
+            sys.stderr.write("were asked for hostlist but attribute mock_dynamic_hosts wasn't set\n")
+
     if options.has_key("-M"):
         if options["-M"] == "pass":
             sys.exit(0)
Index: pacemaker/lib/fencing/st_client.c
===================================================================
--- pacemaker.orig/lib/fencing/st_client.c
+++ pacemaker/lib/fencing/st_client.c
@@ -62,6 +62,7 @@ struct stonith_action_s {
 
     /*! internal async track data */
     int fd_stdout;
+    int fd_stderr;
     int last_timeout_signo;
 
     /*! internal timing information */
@@ -76,6 +77,7 @@ struct stonith_action_s {
     GPid pid;
     int rc;
     char *output;
+    char *error;
 };
 
 typedef struct stonith_private_s {
@@ -153,6 +155,27 @@ int stonith_send_command(stonith_t * sto
 static void stonith_connection_destroy(gpointer user_data);
 static void stonith_send_notification(gpointer data, gpointer user_data);
 static int internal_stonith_action_execute(stonith_action_t * action);
+static void log_action(stonith_action_t *action, pid_t pid);
+
+static void
+log_action(stonith_action_t *action, pid_t pid)
+{
+    if (action->output) {
+        /* Logging the whole string confuses syslog when the string is xml */
+        char *prefix = crm_strdup_printf("%s[%d] stdout:", action->agent, pid);
+
+        crm_log_output(LOG_TRACE, prefix, action->output);
+        free(prefix);
+    }
+
+    if (action->error) {
+        /* Logging the whole string confuses syslog when the string is xml */
+        char *prefix = crm_strdup_printf("%s[%d] stderr:", action->agent, pid);
+
+        crm_log_output(LOG_WARNING, prefix, action->error);
+        free(prefix);
+    }
+}
 
 static void
 stonith_connection_destroy(gpointer user_data)
@@ -554,8 +577,14 @@ stonith_action_clear_tracking_data(stoni
         close(action->fd_stdout);
         action->fd_stdout = 0;
     }
+    if (action->fd_stderr) {
+        close(action->fd_stderr);
+        action->fd_stderr = 0;
+    }
     free(action->output);
     action->output = NULL;
+    free(action->error);
+    action->error = NULL;
     action->rc = 0;
     action->pid = 0;
     action->last_timeout_signo = 0;
@@ -638,7 +667,6 @@ read_output(int fd)
             buffer[more] = 0; /* Make sure its nul-terminated for logging
                               * 'more' is always less than our buffer size
                               */
-            crm_trace("Got %d more bytes: %.200s...", more, buffer);
             output = realloc_safe(output, len + more + 1);
             snprintf(output + len, more + 1, "%s", buffer);
             len += more;
@@ -699,6 +727,9 @@ stonith_action_async_done(mainloop_child
     }
 
     action->output = read_output(action->fd_stdout);
+    action->error = read_output(action->fd_stderr);
+
+    log_action(action, pid);
 
     if (action->rc != pcmk_ok && update_remaining_timeout(action)) {
         int rc = internal_stonith_action_execute(action);
@@ -722,8 +753,10 @@ internal_stonith_action_execute(stonith_
     int total = 0;
     int p_read_fd, p_write_fd;  /* parent read/write file descriptors */
     int c_read_fd, c_write_fd;  /* child read/write file descriptors */
+    int c_stderr_fd, p_stderr_fd; /* parent/child side file descriptors for stderr */
     int fd1[2];
     int fd2[2];
+    int fd3[2];
     int is_retry = 0;
 
     /* clear any previous tracking data */
@@ -740,7 +773,7 @@ internal_stonith_action_execute(stonith_
         is_retry = 1;
     }
 
-    c_read_fd = c_write_fd = p_read_fd = p_write_fd = -1;
+    c_read_fd = c_write_fd = p_read_fd = p_write_fd = c_stderr_fd = p_stderr_fd = -1;
 
     if (action->args == NULL || action->agent == NULL)
         goto fail;
@@ -756,6 +789,11 @@ internal_stonith_action_execute(stonith_
     c_read_fd = fd2[0];
     p_write_fd = fd2[1];
 
+    if (pipe(fd3))
+        goto fail;
+    p_stderr_fd = fd3[0];
+    c_stderr_fd = fd3[1];
+
     crm_debug("forking");
     pid = fork();
     if (pid < 0) {
@@ -775,17 +813,19 @@ internal_stonith_action_execute(stonith_
             goto fail;
         close(2);
         /* coverity[leaked_handle] False positive */
-        if (dup(c_write_fd) < 0)
+        if (dup(c_stderr_fd) < 0)
             goto fail;
         close(0);
         /* coverity[leaked_handle] False positive */
         if (dup(c_read_fd) < 0)
             goto fail;
 
-        /* keep c_write_fd open so parent can report all errors. */
+        /* keep c_stderr_fd open so parent can report all errors. */
+        /* keep c_write_fd open so hostlist can be sent to parent. */
         close(c_read_fd);
         close(p_read_fd);
         close(p_write_fd);
+        close(p_stderr_fd);
 
         if (action->dev_id) {
             setenv(st_dev_id_key, action->dev_id, 1);
@@ -806,6 +846,11 @@ internal_stonith_action_execute(stonith_
         crm_perror(LOG_NOTICE, "Could not change the output of %s to be non-blocking",
                    action->agent);
     }
+    ret = fcntl(p_stderr_fd, F_SETFL, fcntl(p_stderr_fd, F_GETFL, 0) | O_NONBLOCK);
+    if (ret < 0) {
+        crm_perror(LOG_NOTICE, "Could not change the stderr of %s to be non-blocking",
+                   action->agent);
+    }
 
     do {
         crm_debug("sending args");
@@ -829,6 +874,7 @@ internal_stonith_action_execute(stonith_
     /* async */
     if (action->async) {
         action->fd_stdout = p_read_fd;
+        action->fd_stderr = p_stderr_fd;
         mainloop_child_add(pid, 0/* Move the timeout here? */, action->action, action, stonith_action_async_done);
         crm_trace("Op: %s on %s, pid: %d, timeout: %ds", action->action, action->agent, pid,
                   action->remaining_timeout);
@@ -845,6 +891,7 @@ internal_stonith_action_execute(stonith_
 
         close(c_write_fd);
         close(c_read_fd);
+        close(c_stderr_fd);
         return 0;
 
     } else {
@@ -884,8 +931,12 @@ internal_stonith_action_execute(stonith_
         }
 
         action->output = read_output(p_read_fd);
+        action->error = read_output(p_stderr_fd);
 
         action->rc = -ECONNABORTED;
+
+        log_action(action, pid);
+
         rc = action->rc;
         if (timeout == 0) {
             action->rc = -ETIME;
@@ -912,6 +963,9 @@ internal_stonith_action_execute(stonith_
     if (p_write_fd >= 0) {
         close(p_write_fd);
     }
+    if (p_stderr_fd >= 0) {
+        close(p_stderr_fd);
+    }
 
     if (c_read_fd >= 0) {
         close(c_read_fd);
@@ -919,6 +973,9 @@ internal_stonith_action_execute(stonith_
     if (c_write_fd >= 0) {
         close(c_write_fd);
     }
+    if (c_stderr_fd >= 0) {
+        close(c_stderr_fd);
+    }
 
     return rc;
 }
