[PATCH 1/4] ExecCmd: include stdout data in ExecCmdFail if command failed

[Jan Tluka]

ExecCmdFail exception is thrown if a command returns with non-zero
returncode. When this happens only stderr is saved in the exception.
User might want to work with both the stdout and stderr.

This patch saves stdout data along with stderr in this case.

Signed-off-by: Jan Tluka <jtluka(a)redhat.com&gt;
---
 lnst/Common/ExecCmd.py | 11 ++++++++---
 1 file changed, 8 insertions(+), 3 deletions(-)

diff --git a/lnst/Common/ExecCmd.py b/lnst/Common/ExecCmd.py
index d6c92c6..d432c2c 100644
--- a/lnst/Common/ExecCmd.py
+++ b/lnst/Common/ExecCmd.py
@@ -17,10 +17,12 @@ class ExecCmdFail(Exception):
     _cmd = None
     _retval = None
     _stderr = None
+    _stdout = None
     _report_stderr = None
 
-    def __init__(self, cmd=None, retval=None, err="", report_stderr=False):
-        self._stderr = err
+    def __init__(self, cmd=None, retval=None, outs=["", ""],
report_stderr=False):
+        self._stdout = outs[0]
+        self._stderr = outs[1]
         self._retval = retval
         self._report_stderr = report_stderr
 
@@ -30,6 +32,9 @@ class ExecCmdFail(Exception):
     def get_stderr(self):
         return self._stderr
 
+    def get_stdout(self):
+        return self._stdout
+
     def __str__(self):
         retval = ""
         stderr = ""
@@ -63,7 +68,7 @@ def exec_cmd(cmd, die_on_err=True, log_outputs=True,
report_stderr=False):
         if data_stderr:
             log_output(logging.debug, "Stderr", data_stderr)
     if subp.returncode and die_on_err:
-        err = ExecCmdFail(cmd, subp.returncode, data_stderr,report_stderr)
+        err = ExecCmdFail(cmd, subp.returncode, [data_stdout, data_stderr],
report_stderr)
         logging.error(err)
         raise err
 
-- 
2.4.3

[PATCH 2/4] NetTestCommand: include outputs in res_data if command failed

[Jan Tluka]

User is not able to get the stdout or stderr if a command he runs fails
and he specified save_output command run option. This patch saves the
command outputs from ExecCmdFail exception in res_data if requested.

Signed-off-by: Jan Tluka <jtluka(a)redhat.com&gt;
---
 lnst/Common/NetTestCommand.py | 10 +++++++---
 1 file changed, 7 insertions(+), 3 deletions(-)

diff --git a/lnst/Common/NetTestCommand.py b/lnst/Common/NetTestCommand.py
index 409076b..774c26e 100644
--- a/lnst/Common/NetTestCommand.py
+++ b/lnst/Common/NetTestCommand.py
@@ -413,12 +413,16 @@ class NetTestCommandExec(NetTestCommandGeneric):
             if self._save_output:
                 res_data = { "stdout": stdout, "stderr": stderr }
             self.set_pass(res_data)
-        except ExecCmdFail:
+        except ExecCmdFail as e:
+            res_data = None
+            if self._save_output:
+                res_data = { "stdout": e.get_stdout(),
+                             "stderr": e.get_stderr() }
             if "bg_id" in self._command:
                 logging.info("Command probably intentionally killed.
Passing.")
-                self.set_pass()
+                self.set_pass(res_data)
             else:
-                self.set_fail()
+                self.set_fail(res_data)
 
     def _format_cmd_res_header(self):
         cmd_type = self._command["type"]
-- 
2.4.3

[PATCH 3/4] TaskAPI: fix saving of the result after wait intr and kill

[Jan Tluka]

I believe this was a typo in the past. If a command is run in background
and later intr(), kill() or wait() is called on the command the result
was saved in never used self._res variable. The ProcessAPI object has
self._res_cmd variable that keeps the result of a command. Once the command
on background finishes (intr, wait, kill) it should be updated by the
collected data from associated intr, wait, kill commands.

Signed-off-by: Jan Tluka <jtluka(a)redhat.com&gt;
---
 lnst/Controller/Task.py | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/lnst/Controller/Task.py b/lnst/Controller/Task.py
index 54c9d3f..6aac332 100644
--- a/lnst/Controller/Task.py
+++ b/lnst/Controller/Task.py
@@ -670,7 +670,7 @@ class ProcessAPI(object):
                    "type": "wait",
                    "proc_id": self._bg_id,
                    "netns": self._netns}
-            self._res = self._ctl._run_command(cmd)
+            self._cmd_res = self._ctl._run_command(cmd)
 
     def intr(self):
         """ Interrupt the command. """
@@ -679,7 +679,7 @@ class ProcessAPI(object):
                    "type": "intr",
                    "proc_id": self._bg_id,
                    "netns": self._netns}
-            self._res = self._ctl._run_command(cmd)
+            self._cmd_res = self._ctl._run_command(cmd)
 
     def kill(self):
         """
@@ -694,7 +694,7 @@ class ProcessAPI(object):
                    "type": "kill",
                    "proc_id": self._bg_id,
                    "netns": self._netns}
-            self._res = self._ctl._run_command(cmd)
+            self._cmd_res = self._ctl._run_command(cmd)
 
 class VolatileValue(object):
     def __init__(self, func, *args, **kwargs):
-- 
2.4.3

[PATCH 4/4] regression-tests: add test for ProcessAPI get_result in various scenarios

[Jan Tluka]

This is a test set to make sure the collecting outputs of a command
works correctly for processes running both on foreground and background.

Signed-off-by: Jan Tluka <jtluka(a)redhat.com&gt;
---
 regression-tests/tests/28/desc        |  6 ++++++
 regression-tests/tests/28/recipe1.py  | 20 ++++++++++++++++++++
 regression-tests/tests/28/recipe1.xml | 16 ++++++++++++++++
 regression-tests/tests/28/recipe2.py  | 18 ++++++++++++++++++
 regression-tests/tests/28/recipe2.xml | 16 ++++++++++++++++
 regression-tests/tests/28/recipe3.py  | 12 ++++++++++++
 regression-tests/tests/28/recipe3.xml | 16 ++++++++++++++++
 regression-tests/tests/28/recipe4.py  | 15 +++++++++++++++
 regression-tests/tests/28/recipe4.xml | 16 ++++++++++++++++
 regression-tests/tests/28/run.sh      | 34 ++++++++++++++++++++++++++++++++++
 10 files changed, 169 insertions(+)
 create mode 100644 regression-tests/tests/28/desc
 create mode 100644 regression-tests/tests/28/recipe1.py
 create mode 100644 regression-tests/tests/28/recipe1.xml
 create mode 100644 regression-tests/tests/28/recipe2.py
 create mode 100644 regression-tests/tests/28/recipe2.xml
 create mode 100644 regression-tests/tests/28/recipe3.py
 create mode 100644 regression-tests/tests/28/recipe3.xml
 create mode 100644 regression-tests/tests/28/recipe4.py
 create mode 100644 regression-tests/tests/28/recipe4.xml
 create mode 100755 regression-tests/tests/28/run.sh

diff --git a/regression-tests/tests/28/desc b/regression-tests/tests/28/desc
new file mode 100644
index 0000000..8d4477b
--- /dev/null
+++ b/regression-tests/tests/28/desc
@@ -0,0 +1,6 @@
+Check if a user can get result data especially stdout of a background process.
+
+1. by calling intr()
+2. by calling wait()
+3. by calling kill()
+4. when process is not run on background
diff --git a/regression-tests/tests/28/recipe1.py b/regression-tests/tests/28/recipe1.py
new file mode 100644
index 0000000..a0834e9
--- /dev/null
+++ b/regression-tests/tests/28/recipe1.py
@@ -0,0 +1,20 @@
+from lnst.Controller.Task import ctl
+
+m1 = ctl.get_host("testmachine1")
+
+m1.sync_resources(modules=["Custom"], tools=[])
+
+test = m1.run("while true; do echo test; sleep 1; done", bg=True,
save_output="yes")
+
+ctl.wait(5)
+
+test.intr()
+
+output = test.get_result()["res_data"]["stdout"]
+
+custom = ctl.get_module("Custom", options={ "fail": True })
+
+if output.find("test") != -1:
+    custom.update_options({ "fail": False})
+
+m1.run(custom)
diff --git a/regression-tests/tests/28/recipe1.xml
b/regression-tests/tests/28/recipe1.xml
new file mode 100644
index 0000000..cf6bee0
--- /dev/null
+++ b/regression-tests/tests/28/recipe1.xml
@@ -0,0 +1,16 @@
+<lnstrecipe>
+    <network>
+        <host id="testmachine1">
+            <params/>
+            <interfaces>
+                <eth id="phy1" label="testnet">
+                    <addresses>
+                        <address>192.168.100.2/24</address>
+                    </addresses>
+                </eth>
+            </interfaces>
+        </host>
+    </network>
+
+    <task python="recipe1.py"/>
+</lnstrecipe>
diff --git a/regression-tests/tests/28/recipe2.py b/regression-tests/tests/28/recipe2.py
new file mode 100644
index 0000000..b47ff5a
--- /dev/null
+++ b/regression-tests/tests/28/recipe2.py
@@ -0,0 +1,18 @@
+from lnst.Controller.Task import ctl
+
+m1 = ctl.get_host("testmachine1")
+
+m1.sync_resources(modules=["Custom"], tools=[])
+
+test = m1.run("for i in `seq 5`; do echo test; sleep 1; done", bg=True,
save_output="yes")
+
+test.wait()
+
+output = test.get_result()["res_data"]["stdout"]
+
+custom = ctl.get_module("Custom", options={ "fail": True })
+
+if output.find("test") != -1:
+    custom.update_options({ "fail": False})
+
+m1.run(custom)
diff --git a/regression-tests/tests/28/recipe2.xml
b/regression-tests/tests/28/recipe2.xml
new file mode 100644
index 0000000..1cd8070
--- /dev/null
+++ b/regression-tests/tests/28/recipe2.xml
@@ -0,0 +1,16 @@
+<lnstrecipe>
+    <network>
+        <host id="testmachine1">
+            <params/>
+            <interfaces>
+                <eth id="phy1" label="testnet">
+                    <addresses>
+                        <address>192.168.100.2/24</address>
+                    </addresses>
+                </eth>
+            </interfaces>
+        </host>
+    </network>
+
+    <task python="recipe2.py"/>
+</lnstrecipe>
diff --git a/regression-tests/tests/28/recipe3.py b/regression-tests/tests/28/recipe3.py
new file mode 100644
index 0000000..96c5318
--- /dev/null
+++ b/regression-tests/tests/28/recipe3.py
@@ -0,0 +1,12 @@
+from lnst.Controller.Task import ctl
+
+m1 = ctl.get_host("testmachine1")
+
+m1.sync_resources(modules=["Custom"], tools=[])
+
+test = m1.run("while true; do echo test; sleep 1; done", bg=True,
save_output="yes")
+
+ctl.wait(5)
+
+test.kill()
+
diff --git a/regression-tests/tests/28/recipe3.xml
b/regression-tests/tests/28/recipe3.xml
new file mode 100644
index 0000000..2602c68
--- /dev/null
+++ b/regression-tests/tests/28/recipe3.xml
@@ -0,0 +1,16 @@
+<lnstrecipe>
+    <network>
+        <host id="testmachine1">
+            <params/>
+            <interfaces>
+                <eth id="phy1" label="testnet">
+                    <addresses>
+                        <address>192.168.100.2/24</address>
+                    </addresses>
+                </eth>
+            </interfaces>
+        </host>
+    </network>
+
+    <task python="recipe3.py"/>
+</lnstrecipe>
diff --git a/regression-tests/tests/28/recipe4.py b/regression-tests/tests/28/recipe4.py
new file mode 100644
index 0000000..e8e8f99
--- /dev/null
+++ b/regression-tests/tests/28/recipe4.py
@@ -0,0 +1,15 @@
+from lnst.Controller.Task import ctl
+
+m1 = ctl.get_host("testmachine1")
+
+m1.sync_resources(modules=["Custom"], tools=[])
+
+test = m1.run("echo test", save_output="yes")
+output = test.get_result()["res_data"]["stdout"]
+
+custom = ctl.get_module("Custom", options={ "fail": True })
+
+if output.find("test") != -1:
+    custom.update_options({ "fail": False})
+
+m1.run(custom)
diff --git a/regression-tests/tests/28/recipe4.xml
b/regression-tests/tests/28/recipe4.xml
new file mode 100644
index 0000000..fd2452c
--- /dev/null
+++ b/regression-tests/tests/28/recipe4.xml
@@ -0,0 +1,16 @@
+<lnstrecipe>
+    <network>
+        <host id="testmachine1">
+            <params/>
+            <interfaces>
+                <eth id="phy1" label="testnet">
+                    <addresses>
+                        <address>192.168.100.2/24</address>
+                    </addresses>
+                </eth>
+            </interfaces>
+        </host>
+    </network>
+
+    <task python="recipe4.py"/>
+</lnstrecipe>
diff --git a/regression-tests/tests/28/run.sh b/regression-tests/tests/28/run.sh
new file mode 100755
index 0000000..9901282
--- /dev/null
+++ b/regression-tests/tests/28/run.sh
@@ -0,0 +1,34 @@
+#!/bin/bash
+
+. ../lib.sh
+
+init_test
+
+lnst-ctl -d run recipe1.xml | tee test.log
+rv1=${PIPESTATUS[0]}
+log1=`cat test.log`
+
+lnst-ctl -d run recipe2.xml | tee test.log
+rv2=${PIPESTATUS[0]}
+log2=`cat test.log`
+
+lnst-ctl -d run recipe3.xml | tee test.log
+rv3=${PIPESTATUS[0]}
+log3=`cat test.log`
+
+lnst-ctl -d run recipe4.xml | tee test.log
+rv4=${PIPESTATUS[0]}
+log4=`cat test.log`
+
+print_separator
+assert_status "pass" "$rv1"
+assert_status "pass" "$rv2"
+assert_status "pass" "$rv3"
+assert_status "pass" "$rv4"
+assert_log "INFO" "stdout:.*test" "$log1"
+assert_log "INFO" "stdout:.*test" "$log2"
+assert_log "INFO" "stdout:.*test" "$log4"
+
+rm -f test.log
+
+end_test
-- 
2.4.3

[Ondrej Lichtner]

On Wed, Mar 16, 2016 at 10:29:13AM +0100, Jan Tluka wrote:
>  ExecCmdFail exception is thrown if a command returns with non-zero
>  returncode. When this happens only stderr is saved in the exception.
>  User might want to work with both the stdout and stderr.
>  
>  This patch saves stdout data along with stderr in this case.
>  
>  Signed-off-by: Jan Tluka <jtluka(a)redhat.com&gt;
>  ---
>   lnst/Common/ExecCmd.py | 11 ++++++++---
>   1 file changed, 8 insertions(+), 3 deletions(-)
>  
>  diff --git a/lnst/Common/ExecCmd.py b/lnst/Common/ExecCmd.py
>  index d6c92c6..d432c2c 100644
>  --- a/lnst/Common/ExecCmd.py
>  +++ b/lnst/Common/ExecCmd.py
>  @@ -17,10 +17,12 @@ class ExecCmdFail(Exception):
>       _cmd = None
>       _retval = None
>       _stderr = None
>  +    _stdout = None
>       _report_stderr = None
>   
>  -    def __init__(self, cmd=None, retval=None, err="", report_stderr=False):
>  -        self._stderr = err
>  +    def __init__(self, cmd=None, retval=None, outs=["", ""],
> report_stderr=False):
>  +        self._stdout = outs[0]
>  +        self._stderr = outs[1]
>           self._retval = retval
>           self._report_stderr = report_stderr
>   
>  @@ -30,6 +32,9 @@ class ExecCmdFail(Exception):
>       def get_stderr(self):
>           return self._stderr
>   
>  +    def get_stdout(self):
>  +        return self._stdout
>  +
>       def __str__(self):
>           retval = ""
>           stderr = "" 
Could we maybe include the stdout in the __str__ method of the
exception? I'm not sure if it's used anywhere, but it seems like a
reasonable idea if we have it available...

otherwise ack to set:

Acked-by: Ondrej Lichtner <olichtne(a)redhat.com&gt;

[Jan Tluka]

Mon, Mar 21, 2016 at 11:55:02AM CET, olichtne(a)redhat.com wrote:
> On Wed, Mar 16, 2016 at 10:29:13AM +0100, Jan Tluka wrote:
> > ExecCmdFail exception is thrown if a command returns with non-zero
> > returncode. When this happens only stderr is saved in the exception.
> > User might want to work with both the stdout and stderr.
> > 
> > This patch saves stdout data along with stderr in this case.
> > 
> > Signed-off-by: Jan Tluka <jtluka(a)redhat.com&gt;
> > ---
> >  lnst/Common/ExecCmd.py | 11 ++++++++---
> >  1 file changed, 8 insertions(+), 3 deletions(-)
> > 
> > diff --git a/lnst/Common/ExecCmd.py b/lnst/Common/ExecCmd.py
> > index d6c92c6..d432c2c 100644
> > --- a/lnst/Common/ExecCmd.py
> > +++ b/lnst/Common/ExecCmd.py
> > @@ -17,10 +17,12 @@ class ExecCmdFail(Exception):
> >      _cmd = None
> >      _retval = None
> >      _stderr = None
> > +    _stdout = None
> >      _report_stderr = None
> >  
> > -    def __init__(self, cmd=None, retval=None, err="",
> report_stderr=False):
> > -        self._stderr = err
> > +    def __init__(self, cmd=None, retval=None, outs=["", ""],
> report_stderr=False):
> > +        self._stdout = outs[0]
> > +        self._stderr = outs[1]
> >          self._retval = retval
> >          self._report_stderr = report_stderr
> >  
> > @@ -30,6 +32,9 @@ class ExecCmdFail(Exception):
> >      def get_stderr(self):
> >          return self._stderr
> >  
> > +    def get_stdout(self):
> > +        return self._stdout
> > +
> >      def __str__(self):
> >          retval = ""
> >          stderr = ""
>
> Could we maybe include the stdout in the __str__ method of the
> exception? I'm not sure if it's used anywhere, but it seems like a
> reasonable idea if we have it available... 
Yes and no.

When a command fails it usually writes something really short on its
stderr. Currently LNST uses ExecCmdFail.__str__() when reporting it to
the log when the command fails. If we include stdout this will very
likely break the log output formatting, since stdout could be much
longer.

On the other hand it could be handy in some cases but it will need
slightly bigger changes.

While looking at the code it'd probably doable, since by default
report_stderr is disabled, so I could do it the same way and it won't
break anything atm.

I will send it again.

[Jan Tluka]

Mon, Mar 21, 2016 at 01:27:38PM CET, jtluka(a)redhat.com wrote:
> Mon, Mar 21, 2016 at 11:55:02AM CET, olichtne(a)redhat.com wrote:
> >On Wed, Mar 16, 2016 at 10:29:13AM +0100, Jan Tluka wrote:
> >> ExecCmdFail exception is thrown if a command returns with non-zero
> >> returncode. When this happens only stderr is saved in the exception.
> >> User might want to work with both the stdout and stderr.
> >> 
> >> This patch saves stdout data along with stderr in this case.
> >> 
> >> Signed-off-by: Jan Tluka <jtluka(a)redhat.com&gt;
> >> ---
> >>  lnst/Common/ExecCmd.py | 11 ++++++++---
> >>  1 file changed, 8 insertions(+), 3 deletions(-)
> >> 
> >> diff --git a/lnst/Common/ExecCmd.py b/lnst/Common/ExecCmd.py
> >> index d6c92c6..d432c2c 100644
> >> --- a/lnst/Common/ExecCmd.py
> >> +++ b/lnst/Common/ExecCmd.py
> >> @@ -17,10 +17,12 @@ class ExecCmdFail(Exception):
> >>      _cmd = None
> >>      _retval = None
> >>      _stderr = None
> >> +    _stdout = None
> >>      _report_stderr = None
> >>  
> >> -    def __init__(self, cmd=None, retval=None, err="",
> report_stderr=False):
> >> -        self._stderr = err
> >> +    def __init__(self, cmd=None, retval=None, outs=["", ""],
> report_stderr=False):
> >> +        self._stdout = outs[0]
> >> +        self._stderr = outs[1]
> >>          self._retval = retval
> >>          self._report_stderr = report_stderr
> >>  
> >> @@ -30,6 +32,9 @@ class ExecCmdFail(Exception):
> >>      def get_stderr(self):
> >>          return self._stderr
> >>  
> >> +    def get_stdout(self):
> >> +        return self._stdout
> >> +
> >>      def __str__(self):
> >>          retval = ""
> >>          stderr = ""
> >
> >Could we maybe include the stdout in the __str__ method of the
> >exception? I'm not sure if it's used anywhere, but it seems like a
> >reasonable idea if we have it available...
>
> Yes and no.
>
> When a command fails it usually writes something really short on its
> stderr. Currently LNST uses ExecCmdFail.__str__() when reporting it to
> the log when the command fails. If we include stdout this will very
> likely break the log output formatting, since stdout could be much
> longer.
>
> On the other hand it could be handy in some cases but it will need
> slightly bigger changes.
>
> While looking at the code it'd probably doable, since by default
> report_stderr is disabled, so I could do it the same way and it won't
> break anything atm.
>
> I will send it again. 
Taking it back. I don't see any value here. I had a look at the code and
report_stderr is not used at all. It's always set to default or False.

-Jan

[Jan Tluka]

Wed, Mar 16, 2016 at 10:29:13AM CET, jtluka(a)redhat.com wrote:
> ExecCmdFail exception is thrown if a command returns with non-zero
> returncode. When this happens only stderr is saved in the exception.
> User might want to work with both the stdout and stderr.
>
> This patch saves stdout data along with stderr in this case.
>
> Signed-off-by: Jan Tluka <jtluka(a)redhat.com&gt;
> --- 
FYI, I've just applied the set.

-Jan