jenkins-bot has submitted this change and it was merged.
Change subject: Improve logging for wfShellExec() and ignore missing cgroup
......................................................................
Improve logging for wfShellExec() and ignore missing cgroup
Allow limit.sh to log its errors to an MW debug log channel, by opening
a separate FD for private communication.
Ensure that the log FD is always closed (3>&-) before executing a
subprocess, so that MW will not hang waiting for background processes
to close the log FD. This means using a fixed FD number, since the bash
syntax for closing a file requires a literal FD number.
The "exec" debug channel is now intended for production monitoring. In
addition to errors from limit.sh, it also records when a subprocess is
terminated by a signal.
The case where stream_select() returns false was tested by patching PHP
to inject EINTR or EBADF into errno.
When wfShellExec() is used with a memory cgroup, and the cgroup is missing, log
and continue with no cgroup instead of immediately exiting.
Bug: 55709
Change-Id: Ie40befe9c0d00c9a0ddb01077df4afb774d17e15
---
M includes/GlobalFunctions.php
M includes/limit.sh
2 files changed, 199 insertions(+), 74 deletions(-)
Approvals:
Aaron Schulz: Looks good to me, approved
jenkins-bot: Verified
diff --git a/includes/GlobalFunctions.php b/includes/GlobalFunctions.php
index d8e6b36..de1ebcd 100644
--- a/includes/GlobalFunctions.php
+++ b/includes/GlobalFunctions.php
@@ -2714,9 +2714,9 @@
$functions = explode( ',', ini_get( 'disable_functions'
) );
$functions = array_map( 'trim', $functions );
$functions = array_map( 'strtolower', $functions );
- if ( in_array( 'passthru', $functions ) ) {
- wfDebug( "passthru is in disabled_functions\n"
);
- $disabled = 'passthru';
+ if ( in_array( 'proc_open', $functions ) ) {
+ wfDebug( "proc_open is in disabled_functions\n"
);
+ $disabled = 'disabled';
}
}
}
@@ -2728,13 +2728,16 @@
* configuration if supported.
* @param string $cmd Command line, properly escaped for shell.
* @param &$retval null|Mixed optional, will receive the program's exit code.
- * (non-zero is usually failure)
+ * (non-zero is usually failure). If there is an error from
+ * read, select, or proc_open(), this will be set to -1.
* @param array $environ optional environment variables which should be
* added to the executed command environment.
* @param array $limits optional array with limits(filesize, memory, time,
walltime)
* this overwrites the global wgShellMax* limits.
- * @param array $options Array of options. Only one is "duplicateStderr" =>
true, which
- * Which duplicates stderr to stdout, including errors from
limit.sh
+ * @param array $options Array of options:
+ * - duplicateStderr: Set this to true to duplicate stderr to stdout,
+ * including errors from limit.sh
+ *
* @return string collected stdout as a string
*/
function wfShellExec( $cmd, &$retval = null, $environ = array(), $limits =
array(), $options = array() ) {
@@ -2746,7 +2749,7 @@
$retval = 1;
return $disabled == 'safemode' ?
'Unable to run external programs in safe mode.' :
- 'Unable to run external programs, passthru() is
disabled.';
+ 'Unable to run external programs, proc_open() is
disabled.';
}
$includeStderr = isset( $options['duplicateStderr'] ) &&
$options['duplicateStderr'];
@@ -2772,6 +2775,7 @@
}
$cmd = $envcmd . $cmd;
+ $useLogPipe = false;
if ( php_uname( 's' ) == 'Linux' ) {
$time = intval ( isset( $limits['time'] ) ? $limits['time'] :
$wgMaxShellTime );
if ( isset( $limits['walltime'] ) ) {
@@ -2793,8 +2797,10 @@
'MW_CGROUP=' . escapeshellarg(
$wgShellCgroup ) . '; ' .
"MW_MEM_LIMIT=$mem; " .
"MW_FILE_SIZE_LIMIT=$filesize; " .
- "MW_WALL_CLOCK_LIMIT=$wallTime"
+ "MW_WALL_CLOCK_LIMIT=$wallTime; " .
+ "MW_USE_LOG_PIPE=yes"
);
+ $useLogPipe = true;
} elseif ( $includeStderr ) {
$cmd .= ' 2>&1';
}
@@ -2803,19 +2809,126 @@
}
wfDebug( "wfShellExec: $cmd\n" );
- // Default to an unusual value that shouldn't happen naturally,
- // so in the unlikely event of a weird php bug, it would be
- // more obvious what happened.
- $retval = 200;
- ob_start();
- passthru( $cmd, $retval );
- $output = ob_get_contents();
- ob_end_clean();
-
- if ( $retval == 127 ) {
- wfDebugLog( 'exec', "Possibly missing executable file: $cmd\n"
);
+ $desc = array(
+ 0 => array( 'file', 'php://stdin', 'r' ),
+ 1 => array( 'pipe', 'w' ),
+ 2 => array( 'file', 'php://stderr', 'w' ) );
+ if ( $useLogPipe ) {
+ $desc[3] = array( 'pipe', 'w' );
}
- return $output;
+ $pipes = null;
+ $proc = proc_open( $cmd, $desc, $pipes );
+ if ( !$proc ) {
+ wfDebugLog( 'exec', "proc_open() failed: $cmd\n" );
+ $retval = -1;
+ return '';
+ }
+ $outBuffer = $logBuffer = '';
+ $emptyArray = array();
+ $status = false;
+ $logMsg = false;
+
+ // According to the documentation, it is possible for stream_select()
+ // to fail due to EINTR. I haven't managed to induce this in testing
+ // despite sending various signals. If it did happen, the error
+ // message would take the form:
+ //
+ // stream_select(): unable to select [4]: Interrupted system call
(max_fd=5)
+ //
+ // where [4] is the value of the macro EINTR and "Interrupted system
+ // call" is string which according to the Linux manual is "possibly"
+ // localised according to LC_MESSAGES.
+ $eintr = defined( 'SOCKET_EINTR' ) ? SOCKET_EINTR : 4;
+ $eintrMessage = "stream_select(): unable to select [$eintr]";
+
+ while ( true ) {
+ $status = proc_get_status( $proc );
+ if ( !$status['running'] ) {
+ break;
+ }
+ $status = false;
+
+ $readyPipes = $pipes;
+
+ // Clear last error
+ @trigger_error( '' );
+ if ( @stream_select( $readyPipes, $emptyArray, $emptyArray,
null ) === false ) {
+ $error = error_get_last();
+ if ( strncmp( $error['message'], $eintrMessage, strlen(
$eintrMessage ) ) == 0 ) {
+ continue;
+ } else {
+ trigger_error( $error['message'],
E_USER_WARNING );
+ $logMsg = $error['message'];
+ break;
+ }
+ }
+ foreach ( $readyPipes as $fd => $pipe ) {
+ $block = fread( $pipe, 65536 );
+ if ( $block === '' ) {
+ // End of file
+ fclose( $pipes[$fd] );
+ unset( $pipes[$fd] );
+ if ( !$pipes ) {
+ break 2;
+ }
+ } elseif ( $block === false ) {
+ // Read error
+ $logMsg = "Error reading from pipe";
+ break 2;
+ } elseif ( $fd == 1 ) {
+ // From stdout
+ $outBuffer .= $block;
+ } elseif ( $fd == 3 ) {
+ // From log FD
+ $logBuffer .= $block;
+ if ( strpos( $block, "\n" ) !== false ) {
+ $lines = explode( "\n", $logBuffer );
+ $logBuffer = array_pop( $lines );
+ foreach ( $lines as $line ) {
+ wfDebugLog( 'exec', $line );
+ }
+ }
+ }
+ }
+ }
+
+ foreach ( $pipes as $pipe ) {
+ fclose( $pipe );
+ }
+
+ // Use the status previously collected if possible, since
proc_get_status()
+ // just calls waitpid() which will not return anything useful the
second time.
+ if ( $status === false ) {
+ $status = proc_get_status( $proc );
+ }
+
+ if ( $logMsg !== false ) {
+ // Read/select error
+ $retval = -1;
+ proc_close( $proc );
+ } elseif ( $status['signaled'] ) {
+ $logMsg = "Exited with signal {$status['termsig']}";
+ $retval = 128 + $status['termsig'];
+ proc_close( $proc );
+ } else {
+ if ( $status['running'] ) {
+ $retval = proc_close( $proc );
+ } else {
+ $retval = $status['exitcode'];
+ proc_close( $proc );
+ }
+ if ( $retval == 127 ) {
+ $logMsg = "Possibly missing executable file";
+ } elseif ( $retval >= 129 && $retval <= 192 ) {
+ $logMsg = "Probably exited with signal " . ( $retval -
128 );
+ }
+ }
+
+ if ( $logMsg !== false ) {
+ wfDebugLog( 'exec', "$logMsg: $cmd\n" );
+ }
+
+ return $outBuffer;
}
/**
diff --git a/includes/limit.sh b/includes/limit.sh
index 2a1545b..82197b5 100644
--- a/includes/limit.sh
+++ b/includes/limit.sh
@@ -6,58 +6,6 @@
# and is available on most Linux systems. If Perl was distributed with
# BSD::Resource included, we would happily use that instead, but it isn't.
-MW_INCLUDE_STDERR=
-MW_CPU_LIMIT=0
-MW_CGROUP=
-MW_MEM_LIMIT=0
-MW_FILE_SIZE_LIMIT=0
-MW_WALL_CLOCK_LIMIT=0
-
-# Override settings
-eval "$2"
-
-if [ -n "$MW_INCLUDE_STDERR" ]; then
- exec 2>&1
-fi
-
-if [ "$MW_CPU_LIMIT" -gt 0 ]; then
- ulimit -t "$MW_CPU_LIMIT"
-fi
-if [ "$MW_MEM_LIMIT" -gt 0 ]; then
- if [ -n "$MW_CGROUP" ]; then
- # Create cgroup
- if ! mkdir -m 0700 "$MW_CGROUP"/$$; then
- echo "limit.sh: failed to create the cgroup." 1>&2
- exit 1
- fi
- echo $$ > "$MW_CGROUP"/$$/tasks
- if [ -n "$MW_CGROUP_NOTIFY" ]; then
- echo "1" > "$MW_CGROUP"/$$/notify_on_release
- fi
- # Memory
- echo $(($MW_MEM_LIMIT*1024)) >
"$MW_CGROUP"/$$/memory.limit_in_bytes
- # Memory+swap
- echo $(($MW_MEM_LIMIT*1024)) >
"$MW_CGROUP"/$$/memory.memsw.limit_in_bytes
- else
- ulimit -v "$MW_MEM_LIMIT"
- fi
-else
- MW_CGROUP=""
-fi
-if [ "$MW_FILE_SIZE_LIMIT" -gt 0 ]; then
- ulimit -f "$MW_FILE_SIZE_LIMIT"
-fi
-if [ "$MW_WALL_CLOCK_LIMIT" -gt 0 -a -x "/usr/bin/timeout" ]; then
- /usr/bin/timeout $MW_WALL_CLOCK_LIMIT /bin/bash -c "$1"
- STATUS="$?"
- if [ "$STATUS" == 124 ]; then
- echo "limit.sh: timed out." 1>&2
- fi
-else
- eval "$1"
- STATUS="$?"
-fi
-
# Clean up cgroup
cleanup() {
# First we have to move the current task into a "garbage" group,
otherwise
@@ -66,7 +14,7 @@
if [ -w "$MW_CGROUP"/tasks ]; then
GARBAGE="$MW_CGROUP"
else
- GARBAGE="$MW_CGROUP"/garbage-"$USER"
+ GARBAGE="$MW_CGROUP"/garbage-`id -un`
if [ ! -e "$GARBAGE" ]; then
mkdir -m 0700 "$GARBAGE"
fi
@@ -85,6 +33,70 @@
NUM_TASKS=${#MAPFILE[*]}
}
+log() {
+ echo limit.sh: "$*" >&3
+ echo limit.sh: "$*" >&2
+}
+
+MW_INCLUDE_STDERR=
+MW_USE_LOG_PIPE=
+MW_CPU_LIMIT=0
+MW_CGROUP=
+MW_MEM_LIMIT=0
+MW_FILE_SIZE_LIMIT=0
+MW_WALL_CLOCK_LIMIT=0
+
+# Override settings
+eval "$2"
+
+if [ -n "$MW_INCLUDE_STDERR" ]; then
+ exec 2>&1
+fi
+if [ -z "$MW_USE_LOG_PIPE" ]; then
+ # Open a dummy log FD
+ exec 3>/dev/null
+fi
+
+if [ "$MW_CPU_LIMIT" -gt 0 ]; then
+ ulimit -t "$MW_CPU_LIMIT"
+fi
+if [ "$MW_MEM_LIMIT" -gt 0 ]; then
+ if [ -n "$MW_CGROUP" ]; then
+ # Create cgroup
+ if ! mkdir -m 0700 "$MW_CGROUP"/$$; then
+ log "failed to create the cgroup."
+ MW_CGROUP=""
+ fi
+ fi
+ if [ -n "$MW_CGROUP" ]; then
+ echo $$ > "$MW_CGROUP"/$$/tasks
+ if [ -n "$MW_CGROUP_NOTIFY" ]; then
+ echo "1" > "$MW_CGROUP"/$$/notify_on_release
+ fi
+ # Memory
+ echo $(($MW_MEM_LIMIT*1024)) >
"$MW_CGROUP"/$$/memory.limit_in_bytes
+ # Memory+swap
+ echo $(($MW_MEM_LIMIT*1024)) >
"$MW_CGROUP"/$$/memory.memsw.limit_in_bytes
+ else
+ ulimit -v "$MW_MEM_LIMIT"
+ fi
+else
+ MW_CGROUP=""
+fi
+if [ "$MW_FILE_SIZE_LIMIT" -gt 0 ]; then
+ ulimit -f "$MW_FILE_SIZE_LIMIT"
+fi
+if [ "$MW_WALL_CLOCK_LIMIT" -gt 0 -a -x "/usr/bin/timeout" ]; then
+ /usr/bin/timeout $MW_WALL_CLOCK_LIMIT /bin/bash -c "$1" 3>&-
+ STATUS="$?"
+ if [ "$STATUS" == 124 ]; then
+ log "timed out executing command \"$1\""
+ fi
+else
+ eval "$1" 3>&-
+ STATUS="$?"
+fi
+
if [ -n "$MW_CGROUP" ]; then
updateTaskCount
@@ -97,7 +109,7 @@
updateTaskCount
done
cleanup
- ) >&/dev/null < /dev/null &
+ ) >&/dev/null < /dev/null 3>&- &
disown -a
else
cleanup
--
To view, visit https://gerrit.wikimedia.org/r/91115
To unsubscribe, visit https://gerrit.wikimedia.org/r/settings
Gerrit-MessageType: merged
Gerrit-Change-Id: Ie40befe9c0d00c9a0ddb01077df4afb774d17e15
Gerrit-PatchSet: 3
Gerrit-Project: mediawiki/core
Gerrit-Branch: master
Gerrit-Owner: Tim Starling <[email protected]>
Gerrit-Reviewer: Aaron Schulz <[email protected]>
Gerrit-Reviewer: Faidon Liambotis <[email protected]>
Gerrit-Reviewer: Parent5446 <[email protected]>
Gerrit-Reviewer: PleaseStand <[email protected]>
Gerrit-Reviewer: Tim Starling <[email protected]>
Gerrit-Reviewer: jenkins-bot
_______________________________________________
MediaWiki-commits mailing list
[email protected]
https://lists.wikimedia.org/mailman/listinfo/mediawiki-commits
