hcq/MaxScale
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

MXS-1405: Capture subprocess output

Browse Source 
The output by the subprocesses launched by the externcmd system is now
captured and logged.
This commit is contained in:
Markus Mäkelä
2017-09-14 18:09:35 +03:00
parent eab7b7e2a3
commit 7e6e8d3e29
3 changed files with 108 additions and 52 deletions
Download Patch File Download Diff File Expand all files Collapse all files

129
server/core/externcmd.cc
View File

@ -17,14 +17,14 @@
#include <errno.h> #include <errno.h>
#include <string.h> #include <string.h>
#include <sys/wait.h> #include <sys/wait.h>
#include <fcntl.h>
#include <string>
#include <maxscale/alloc.h> #include <maxscale/alloc.h>
#include <maxscale/log_manager.h> #include <maxscale/log_manager.h>
#include <maxscale/pcre2.h> #include <maxscale/pcre2.h>
#include <maxscale/thread.h> #include <maxscale/thread.h>
/** /**
* Tokenize a string into arguments suitable for a `execvp` call * Tokenize a string into arguments suitable for a `execvp` call
* *
@ -159,8 +159,24 @@ void externcmd_free(EXTERNCMD* cmd)
} }
} }
int externcmd_execute(EXTERNCMD* cmd) int externcmd_execute(EXTERNCMD* cmd, char** dest)
{ {
// Always set dest to NULL before starting
*dest = NULL;
// Create a pipe where the command can print output
int fd[2];
if (pipe(fd) == -1)
{
MXS_ERROR("Failed to open pipe: [%d] %s", errno, mxs_strerror(errno));
return -1;
}
// Make them non-blocking
fcntl(fd[0], F_SETFL, O_NONBLOCK);
fcntl(fd[1], F_SETFL, O_NONBLOCK);
int rval = 0; int rval = 0;
pid_t pid; pid_t pid;
@ -170,14 +186,25 @@ int externcmd_execute(EXTERNCMD* cmd)
if (pid < 0) if (pid < 0)
{ {
close(fd[0]);
close(fd[1]);
MXS_ERROR("Failed to execute command '%s', fork failed: [%d] %s", MXS_ERROR("Failed to execute command '%s', fork failed: [%d] %s",
cmd->argv[0], errno, mxs_strerror(errno)); cmd->argv[0], errno, mxs_strerror(errno));
rval = -1; rval = -1;
} }
else if (pid == 0) else if (pid == 0)
{ {
/** Child process, execute command */ // This is the child process. Close the read end of the pipe and redirect
// both stdout and stderr to the write end of the pipe
close(fd[0]);
dup2(fd[1], STDOUT_FILENO);
dup2(fd[1], STDERR_FILENO);
// Execute the command
execvp(cmd->argv[0], cmd->argv); execvp(cmd->argv[0], cmd->argv);
// Close the write end of the pipe and exit
close(fd[1]);
_exit(1); _exit(1);
} }
else else
@ -186,67 +213,83 @@ int externcmd_execute(EXTERNCMD* cmd)
cmd->child = pid; cmd->child = pid;
cmd->n_exec++; cmd->n_exec++;
std::string output;
bool first_warning = true; bool first_warning = true;
bool again = true; bool again = true;
uint64_t t = 0; uint64_t t = 0;
uint64_t t_max = cmd->timeout * 1000; uint64_t t_max = cmd->timeout * 1000;
// Close the write end of the pipe
close(fd[1]);
while (again) while (again)
{ {
int exit_status; int exit_status;
switch (waitpid(pid, &exit_status, WNOHANG)) switch (waitpid(pid, &exit_status, WNOHANG))
{ {
case -1: case -1:
MXS_ERROR("Failed to wait for child process: %d, %s", errno, mxs_strerror(errno)); MXS_ERROR("Failed to wait for child process: %d, %s", errno, mxs_strerror(errno));
again = false; again = false;
break; break;
case 0: case 0:
if (t++ > t_max) if (t++ > t_max)
{
// Command timed out
t = 0;
if (first_warning)
{ {
// Command timed out MXS_WARNING("Soft timeout for command '%s', sending SIGTERM", cmd->argv[0]);
t = 0; kill(pid, SIGTERM);
if (first_warning) first_warning = false;
{
MXS_WARNING("Soft timeout for command '%s', sending SIGTERM", cmd->argv[0]);
kill(pid, SIGTERM);
first_warning = false;
}
else
{
MXS_ERROR("Hard timeout for command '%s', sending SIGKILL", cmd->argv[0]);
kill(pid, SIGKILL);
}
} }
else else
{ {
// Sleep and try again MXS_ERROR("Hard timeout for command '%s', sending SIGKILL", cmd->argv[0]);
thread_millisleep(1); kill(pid, SIGKILL);
} }
break; }
else
{
// Sleep and try again
thread_millisleep(1);
}
break;
default: default:
again = false; again = false;
if (WIFEXITED(exit_status)) if (WIFEXITED(exit_status))
{ {
rval = WEXITSTATUS(exit_status); rval = WEXITSTATUS(exit_status);
} }
else if (WIFSIGNALED(exit_status)) else if (WIFSIGNALED(exit_status))
{ {
rval = WTERMSIG(exit_status); rval = WTERMSIG(exit_status);
} }
else else
{ {
rval = exit_status; rval = exit_status;
MXS_ERROR("Command '%s' did not exit normally. Exit status: %d", MXS_ERROR("Command '%s' did not exit normally. Exit status: %d",
cmd->argv[0], exit_status); cmd->argv[0], exit_status);
} }
break; break;
}
int n;
char buf[4096]; // This seems like enough space
while ((n = read(fd[0], buf, sizeof(buf))) > 0)
{
// Read all available output
output.append(buf, n);
} }
} }
// Close the read end of the pipe and copy the data to the output parameter
close(fd[0]);
*dest = MXS_STRDUP_A(output.c_str());
} }
return rval; return rval;

7
server/core/maxscale/externcmd.h
View File

@ -55,11 +55,14 @@ void externcmd_free(EXTERNCMD* cmd);
/** /**
* Execute a command * Execute a command
* *
* @param cmd Command to execute * The output of the command must be freed by the caller by calling MXS_FREE.
*
* @param cmd Command to execute
* @param dest Pointer where to store the output of the command
* *
* @return The return value of the executed command or -1 on error * @return The return value of the executed command or -1 on error
*/ */
int externcmd_execute(EXTERNCMD* cmd); int externcmd_execute(EXTERNCMD* cmd, char** dest);
/** /**
* Substitute all occurrences of @c match with @c replace in the arguments for @c cmd * Substitute all occurrences of @c match with @c replace in the arguments for @c cmd

24
server/core/monitor.cc
View File

@ -1209,21 +1209,29 @@ monitor_launch_script(MXS_MONITOR* mon, MXS_MONITOR_SERVERS* ptr, const char* sc
externcmd_substitute_arg(cmd, "[$]SYNCEDLIST", nodelist); externcmd_substitute_arg(cmd, "[$]SYNCEDLIST", nodelist);
} }
int rv = externcmd_execute(cmd); char* out = NULL;
std::string str;
int rv = externcmd_execute(cmd, &out);
if (out)
{
str = trim(out);
MXS_FREE(out);
}
if (rv) if (rv)
{ {
if (rv == -1) if (rv == -1)
{ {
// Internal error // Internal error
MXS_ERROR("Failed to execute script '%s' on server state change event '%s'", MXS_ERROR("Failed to execute script '%s' on server state change event '%s': %s",
script, mon_get_event_name(ptr)); script, mon_get_event_name(ptr), str.c_str());
} }
else else
{ {
// Script returned a non-zero value // Script returned a non-zero value
MXS_ERROR("Script '%s' returned %d on event '%s'", MXS_ERROR("Script '%s' returned %d on event '%s': %s",
script, rv, mon_get_event_name(ptr)); script, rv, mon_get_event_name(ptr), str.c_str());
} }
} }
else else
@ -1264,8 +1272,10 @@ monitor_launch_script(MXS_MONITOR* mon, MXS_MONITOR_SERVERS* ptr, const char* sc
memError = true; memError = true;
scriptStr = cmd->argv[0]; // print at least something scriptStr = cmd->argv[0]; // print at least something
} }
MXS_NOTICE("Executed monitor script '%s' on event '%s'.",
scriptStr, mon_get_event_name(ptr)); MXS_NOTICE("Executed monitor script '%s' on event '%s': %s",
scriptStr, mon_get_event_name(ptr), str.c_str());
if (!memError) if (!memError)
{ {
MXS_FREE(scriptStr); MXS_FREE(scriptStr);