Bug 849394

Summary: rhq-script-plugin does not always capture process output; causes spurious failures
Product: [Other] RHQ Project Reporter: Elias Ross <genman>
Component: PluginsAssignee: John Mazzitelli <mazz>
Status: CLOSED CURRENTRELEASE QA Contact: Mike Foley <mfoley>
Severity: high Docs Contact:
Priority: high    
Version: 4.4CC: hrupp, mazz
Target Milestone: ---   
Target Release: RHQ 4.5.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 871606 (view as bug list) Environment:
Last Closed: 2013-09-01 10:10:47 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 871606    
Attachments:
Description Flags
fixes process leak
none
Ensure output thread completes before exiting startProgram
none
optional use of a thread pool none

Description Elias Ross 2012-08-19 04:57:21 UTC
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 06:15:08 UTC
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 22:02:49 UTC
Created attachment 612648 [details]
fixes process leak

Comment 3 John Mazzitelli 2012-09-18 19:19:42 UTC
(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 21:07:02 UTC
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 21:08:50 UTC
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 21:20:41 UTC
git commit to master: bf4b25f421769909e886eb42f7b99c66b207b200

Comment 7 Charles Crouch 2012-10-30 21:26:43 UTC
Setting correct Target Release.

Comment 8 John Mazzitelli 2012-11-12 18:41:41 UTC
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 18:47:50 UTC
git commit to deprecate old API: e4b77aefd05bd093816e46792a928c49d2f3b402

Comment 10 Heiko W. Rupp 2013-09-01 10:10:47 UTC
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.