Bug 849394 - rhq-script-plugin does not always capture process output; causes spurious failures
rhq-script-plugin does not always capture process output; causes spurious fai...
Status: CLOSED CURRENTRELEASE
Product: RHQ Project
Classification: Other
Component: Plugins (Show other bugs)
4.4
Unspecified Unspecified
high Severity high (vote)
: ---
: RHQ 4.5.0
Assigned To: John Mazzitelli
Mike Foley
:
Depends On:
Blocks: 871606
  Show dependency treegraph
 
Reported: 2012-08-19 00:57 EDT by Elias Ross
Modified: 2013-09-01 06:10 EDT (History)
2 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 871606 (view as bug list)
Environment:
Last Closed: 2013-09-01 06:10:47 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:


Attachments (Terms of Use)
fixes process leak (8.57 KB, patch)
2012-09-13 18:02 EDT, Elias Ross
no flags Details | Diff
Ensure output thread completes before exiting startProgram (10.15 KB, patch)
2012-09-18 17:07 EDT, Elias Ross
no flags Details | Diff
optional use of a thread pool (6.28 KB, patch)
2012-09-18 17:08 EDT, Elias Ross
no flags Details | Diff

  None (edit)
Description Elias Ross 2012-08-19 00:57:21 EDT
Description of problem:

I configured the 'script' plugin to watch for output when checking for availability of my resource.

I check the results using a regex check. In some cases, the output is empty. Then RHQ assumes the resource is down, when in fact it is up.

For example, /sbin/service is called with the name of my service. In some cases no output appears.

2012-08-18 21:09:38,052 DEBUG [ResourceContainer.invoker.daemon-115] (org.rhq.plugins.script.ScriptServerComponent)- [/sbin/service]: CLI results: exitcode=[0]; error=[null]; output=
2012-08-18 21:09:38,052 DEBUG [ResourceContainer.invoker.daemon-115] (org.rhq.plugins.script.ScriptServerComponent)- [/sbin/service]: CLI output [] did not match regex [(?s).*is running.*], resource is considered DOWN

Version-Release number of selected component (if applicable):

RHQ 4.2 plugin

How reproducible:

Eventually is.

Additional info:

modules/core/util/src/main/java/org/rhq/core/util/exec/ProcessExecutor.java contains this unfortunate note:

        // WARNING:
        // It seems there is no way to get around a possible race condition - what if the process
        // was so fast that it exited already?  We didn't get a chance to capture its output.
        // I see a unit test that periodically fails because it doesn't get any captured output when
        // it should - I think it is because of this race condition.  But there is no Java API that
        // let's me redirect a process' streams before the process is told to start.

It's unclear if this is really still the case or not...

http://stackoverflow.com/questions/1670798/using-a-thread-to-capture-process-output

There is a note that I/O needs to be consumed in a thread. It could be the process completes but the I/O was never consumed.
Comment 1 Elias Ross 2012-08-19 02:15:08 EDT
The problem is that the I/O threads are never run to completion: The main process waits for the exit status, but the I/O threads may not have starts.

I will provide a patch, but the solution is simply to return a handle containing both stdout/stderr Thread instances and wait for these threads...

modules/core/util/src/main/java/org/rhq/core/util/exec/ProcessExecutor.java

    /**
     * Wrapper for threads used for capturing output.
     * Call {@link #join} to wait for output to be fully captured.
     */
    protected static class RedirectThreads {

        private final StreamRedirector stdout;
        private final StreamRedirector stderr;

...

    protected RedirectThreads redirectStreams(ProcessToStart process, Process childProcess) throws IOException {
...
        return new RedirectThreads(stdoutThread, stderrThread);

then ... 

+        final RedirectThreads redirect = redirectStreams(process, childProcess);
...
-                        int exitCode = childProcess.waitFor();
-                        retExitCode[0] = new Integer(exitCode);
+                    } finally {
+                        redirect.join();
                     }

Simple as this.
Comment 2 Elias Ross 2012-09-13 18:02:49 EDT
Created attachment 612648 [details]
fixes process leak
Comment 3 John Mazzitelli 2012-09-18 15:19:42 EDT
(In reply to comment #2)
> Created attachment 612648 [details]
> fixes process leak

I think the wrong patch was attached - the attached patch deals with PIQL queries. Can you remove that patch and attach the one for this issue?
Comment 4 Elias Ross 2012-09-18 17:07:02 EDT
Created attachment 614123 [details]
Ensure output thread completes before exiting startProgram

Sorry I had the wrong patch.

One thing you might want to adjust (for sake of the build) is adjust the number of times we check for correct output:

modules/core/util/src/test/java/org/rhq/core/util/exec/ProcessExecTest.java

diff --git a/modules/core/util/src/test/java/org/rhq/core/util/exec/ProcessExecTest.java b/modules/core/util/src/test/java/org/rhq/core/util/exec/ProcessExecTest.java
index 49ab3f5..60b7aed 100644
--- a/modules/core/util/src/test/java/org/rhq/core/util/exec/ProcessExecTest.java
+++ b/modules/core/util/src/test/java/org/rhq/core/util/exec/ProcessExecTest.java
@@ -35,7 +35,7 @@
 public class ProcessExecTest {
     public void testProcessExecOutputStream() {
         // run multiple times to ensure race condition fixed
-        for (int i = 0; i < 100; i++) {
+        for (int i = 0; i < 10; i++) {
             ProcessToStart start = new ProcessToStart();

             setupProgram(start);

I also have a version with thread pools being attached. I don't think a thread pool is worth it, but might be good idea.
Comment 5 Elias Ross 2012-09-18 17:08:50 EDT
Created attachment 614124 [details]
optional use of a thread pool

Additional possible change to use a thread pool to handle I/O redirect. Might be good if there are a lot of script executions, though I don't know if it is worth it for the average case.
Comment 6 John Mazzitelli 2012-09-18 17:20:41 EDT
git commit to master: bf4b25f421769909e886eb42f7b99c66b207b200
Comment 7 Charles Crouch 2012-10-30 17:26:43 EDT
Setting correct Target Release.
Comment 8 John Mazzitelli 2012-11-12 13:41:41 EST
need to fix the api change (redirectStreams is protected, so we want to maintain that API and @Deprecate it, and change the name of the new method and use that one).
Comment 9 John Mazzitelli 2012-11-12 13:47:50 EST
git commit to deprecate old API: e4b77aefd05bd093816e46792a928c49d2f3b402
Comment 10 Heiko W. Rupp 2013-09-01 06:10:47 EDT
Bulk closing of items that are on_qa and in old RHQ releases, which are out for a long time and where the issue has not been re-opened since.

Note You need to log in before you can comment on or make changes to this bug.