[Avocado-devel] option --output-check-record behavior
Lucas Meneghel Rodrigues
lookkas at gmail.com
Thu Sep 8 19:05:23 UTC 2016
Yep, that was the problem. The pipe won't work if shell=False (default).
Now, on the rationale why shell=False is the default, basically, it's
unsafe, see:
https://docs.python.org/2/library/subprocess.html
With shell=True, the expected standard output starts to appear.
On Thu, Sep 8, 2016 at 4:01 PM Lucas Meneghel Rodrigues <lookkas at gmail.com>
wrote:
> By the way, you *must* set shell=True to use pipes (which I did forget).
> Otherwise the pipes won't work.
>
> On Thu, Sep 8, 2016 at 4:00 PM Lucas Meneghel Rodrigues <lookkas at gmail.com>
> wrote:
>
>> I think you guys are missing the point here. I just tried Marcos's test
>> here and that's what I get with Avocado LTS 36.2:
>>
>> $ avocado run xentest.py --output-check-record all
>> JOB ID : c44d95698bc6a20329691a9c10370c3b63c8944f
>> JOB LOG :
>> /home/lmr/avocado/job-results/job-2016-09-08T15.54-c44d956/job.log
>> TESTS : 1
>> (1/1) xentest.py:xentest.test_xen_start_stop: ERROR (0.01 s)
>> RESULTS : PASS 0 | ERROR 1 | FAIL 0 | SKIP 0 | WARN 0 | INTERRUPT 0
>> JOB HTML :
>> /home/lmr/avocado/job-results/job-2016-09-08T15.54-c44d956/html/results.html
>> TESTS TIME : 0.01 s
>> $ ls
>> xentest.py xentest.pyc xentest.py.data
>> $ cat xentest.py.data/stdout.expected
>> $ cat xentest.py.data/stderr.expected
>> xc: error: Could not obtain handle on privileged command interface (2 =
>> No such file or directory): Internal error
>> libxl: error: libxl.c:116:libxl_ctx_alloc: cannot open libxc handle: No
>> such file or directory
>> cannot init xl context
>>
>> Keep in mind that I have installed only the basic xen packages, so my
>> 'xl' doesn't work. Avocado does its job and creates xentest.py.data, with
>> the expected outputs.
>>
>> So no, you don't need to avoid the pipes, and everything should work. The
>> caveat is that avocado creates xentest.py.data with the recorded files in
>> the same dir of your test file. You have to test that with your version of
>> avocado and verify if the directory/files are created or not. If not, it's
>> a bug, although I think we have a functional test to avoid such a bug.
>>
>> So for me here, everything is worked as designed. I modified xentest.py
>> to use avocado libs:
>>
>> #!/usr/bin/env python
>> # vim: tabstop=8 expandtab shiftwidth=4 softtabstop=4
>>
>> import os
>> import sys
>> import string
>> import logging
>> import commands
>> import time
>>
>> from avocado import Test
>> from avocado import main
>> from avocado.utils import process
>> from autotest.client import utils
>> from autotest.client import xen
>>
>> progress_log = logging.getLogger("progress")
>>
>> class xentest(Test):
>> """
>> Test
>> """
>> def exec_xl(self):
>> """
>> Start xen Guest
>> """
>> sleeptime = self.params.get('sleep_time')
>> guestdef = self.params.get('guest_cfg')
>> runaction = self.params.get('run_action')
>> domname = self.params.get('domain_name')
>> progress_log.info('%s: Running action %s', self.name, runaction)
>> time.sleep(sleeptime)
>> if runaction == 'create':
>> cmd = ('/usr/sbin/xl %s %s' % (runaction, guestdef))
>> if process.system(cmd, ignore_status=False) == "0":
>> pass
>> else:
>> return False
>> else:
>> cmd = ('/usr/sbin/xl %s %s' % (runaction, domname))
>> if process.system(cmd, ignore_status=False) == "0":
>> pass
>> else:
>> return False
>>
>> def test_xen_start_stop(self):
>> """
>> Get Xen version
>> """
>> fd = open('/tmp/xenver.log', 'w')
>> fd.write('### %s\n' % time.time())
>> cmd = "xl info|grep xen_version| awk '{print $3}'"
>> xenversion = process.system_output(cmd, ignore_status=False)
>> process.system('ls -la /usr/share/avocado/tests 2>&1')
>> print('Xen Version = %s.\n' % xenversion)
>> fd.write('Xen Version = %s.\n' % xenversion)
>> fd.write('### %s\n' % time.time())
>> if self.exec_xl() == "0":
>> pass
>> else:
>> return False
>> fd.close()
>>
>> if __name__ == "__main__":
>> main()
>>
>> I hope this helps,
>>
>> Lucas
>>
>> On Thu, Sep 8, 2016 at 3:55 PM Marcos E. Matsunaga <
>> Marcos.Matsunaga at oracle.com> wrote:
>>
>>> Thanks Amador,
>>>
>>> I assumed it would have the same behavior as utils.system and completely
>>> ignored the pipe.
>>>
>>>
>>>
>>> On 09/08/2016 07:39 PM, Amador Segundo wrote:
>>>
>>> On Sep 8, 2016 8:19 PM, "Marcos E. Matsunaga" <
>>> Marcos.Matsunaga at oracle.com> wrote:
>>> >
>>> > Hi Cleber,
>>> >
>>> > Sorry for being a pain. I've tried to use process.system to execute
>>> commands, but I got an error, that's why I kept the autotest libraries (I
>>> actually copied from one of the files in io-github-autotest-libvirt).
>>> >
>>> > The error I'm getting is:
>>> >
>>> > 2016-09-08 13:49:25,844 sysinfo L0371 INFO | Profiler disabled
>>> > 2016-09-08 13:49:25,845 test L0214 INFO | START
>>> 1-/root/avocado-vt/io-fs-autotest-xen/xen/tests/xentest.py:xentest.test_xen_start_stop;1
>>> > 2016-09-08 13:49:25,846 process L0334 INFO | Running 'xl
>>> info|grep xen_version| awk '{print $3}''
>>> > 2016-09-08 13:49:25,863 process L0435 INFO | Command 'xl
>>> info|grep xen_version| awk '{print $3}'' finished with 1 after
>>> 0.00377798080444s
>>>
>>> The problem here is the pipe. You can collect the output and parse it
>>> inside the python code. Something.like:
>>>
>>> output = process.system_output("xl info")
>>> for line in output.splitlines():
>>> if 'xen_version' in line:
>>> var = line.split()[3]
>>> break
>>> ...
>>>
>>> > 2016-09-08 13:49:25,863 stacktrace L0038 ERROR|
>>> > 2016-09-08 13:49:25,863 stacktrace L0041 ERROR| Reproduced
>>> traceback from: /usr/lib/python2.7/site-packages/avocado/core/test.py:448
>>> > 2016-09-08 13:49:25,864 stacktrace L0044 ERROR| Traceback (most
>>> recent call last):
>>> > 2016-09-08 13:49:25,864 stacktrace L0044 ERROR| File
>>> "/root/avocado-vt/io-fs-autotest-xen/xen/tests/xentest.py", line 52, in
>>> test_xen_start_stop
>>> > 2016-09-08 13:49:25,864 stacktrace L0044 ERROR| xenversion =
>>> process.system_output(cmd, ignore_status=False)
>>> > 2016-09-08 13:49:25,864 stacktrace L0044 ERROR| File
>>> "/usr/lib/python2.7/site-packages/avocado/utils/process.py", line 1139, in
>>> system_output
>>> > 2016-09-08 13:49:25,864 stacktrace L0044 ERROR| sudo=sudo)
>>> > 2016-09-08 13:49:25,864 stacktrace L0044 ERROR| File
>>> "/usr/lib/python2.7/site-packages/avocado/utils/process.py", line 1046, in
>>> run
>>> > 2016-09-08 13:49:25,864 stacktrace L0044 ERROR| raise
>>> CmdError(cmd, sp.result)
>>> > 2016-09-08 13:49:25,864 stacktrace L0044 ERROR| CmdError:
>>> Command 'xl info|grep xen_version| awk '{print $3}'' failed (rc=1)
>>> > 2016-09-08 13:49:25,864 stacktrace L0045 ERROR|
>>> > 2016-09-08 13:49:25,865 test L0563 ERROR| Traceback (most
>>> recent call last):
>>> >
>>> > 2016-09-08 13:49:25,865 test L0563 ERROR| File
>>> "/usr/lib/python2.7/site-packages/avocado/core/test.py", line 503, in
>>> _run_avocado
>>> > raise test_exception
>>> >
>>> > 2016-09-08 13:49:25,865 test L0563 ERROR| CmdError:
>>> Command 'xl info|grep xen_version| awk '{print $3}'' failed (rc=1)
>>> >
>>> > I looked at
>>> "/usr/lib/python2.7/site-packages/avocado/utils/process.py", line 1139 and
>>> didn't see anything that could be causing the problem. I even tried to add
>>> "sudo=False" argument in process.system, but I get the same error.
>>> >
>>> > Thanks again.
>>> >
>>> >
>>> > On 09/08/2016 06:36 PM, Cleber Rosa wrote:
>>> >>
>>> >> On 09/08/2016 01:50 PM, Marcos E. Matsunaga wrote:
>>> >>>
>>> >>> On 09/08/2016 05:44 PM, Cleber Rosa wrote:
>>> >>>>
>>> >>>> On 09/08/2016 11:34 AM, Marcos E. Matsunaga wrote:
>>> >>>>>
>>> >>>>> Hi Cleber,
>>> >>>>>
>>> >>>>> Thanks for your quick reply. That's exactly what I understood, but
>>> here
>>> >>>>> is what is happening
>>> >>>>>
>>> >>>>> I have a directory ~/avocado/xen/tests where I have the xentest.py
>>> >>>>> script. When I execute it, it does create the directory
>>> >>>>> ~/avocado/xen/tests/xentest.py.data with stderr.expected and
>>> >>>>> stdout.expected (empty). It also creates the two files (stdout and
>>> >>>>> stderr) in the job-results/latest directory, but also empty.
>>> >>>>>
>>> >>>>> The weird thing is that instead of saving, it reports to the
>>> job.log as
>>> >>>>> an error "L0151 ERROR| [stderr] Parsing config from /VM/guest1/
>>> vm.cf".
>>> >>>>>
>>> >>>>> That's why I think I am missing something.
>>> >>>>
>>> >>>> Can you post the full test code and the resulting `job.log` file?
>>> >>>
>>> >>> Sure.. It is attached.
>>> >>> And the multiplex file I am using is:
>>> >>>
>>> >>> xentest:
>>> >>> guest1:
>>> >>> action: !mux
>>> >>> start:
>>> >>> run_action: "create"
>>> >>> domain_name: "perf1"
>>> >>> sleep_time: 1
>>> >>> stop:
>>> >>> run_action: "shutdown"
>>> >>> domain_name: "perf1"
>>> >>> sleep_time: 60
>>> >>> guest_cfg: /Repo/VM/perf1/vm.cfg
>>> >>>
>>> >>>>> Thanks again for your help.
>>> >>>>>
>>> >>>>> On 09/08/2016 02:59 PM, Cleber Rosa wrote:
>>> >>>>>>
>>> >>>>>> On 09/08/2016 10:25 AM, Marcos E. Matsunaga wrote:
>>> >>>>>>>
>>> >>>>>>> Hi All,
>>> >>>>>>>
>>> >>>>>>> I am new to avocado and have just started to look into it.
>>> >>>>>>>
>>> >>>>>>> I have been playing with avocado on Fedora 24 for a few weeks. I
>>> >>>>>>> wrote a
>>> >>>>>>> small script to run commands and was exploring the option
>>> >>>>>>> "--output-check-record", but it never populate the files
>>> >>>>>>> stderr.expected
>>> >>>>>>> and stdout.expected. Instead, it prints an error with "[stderr]"
>>> in
>>> >>>>>>> the
>>> >>>>>>> job.log file. My understanding is that the output (stderr and
>>> stdout)
>>> >>>>>>> of commands/scripts executed by avocado would be captured and
>>> saved on
>>> >>>>>>> those files (like on synctest.py example), but it doesn't. I
>>> want to
>>> >>>>>>> know if I am doing something wrong or it is a bug.
>>> >>>>>>>
>>> >>>>>> Hi Marcos,
>>> >>>>>>
>>> >>>>>> Avocado creates the `stdout` and `stderr` files in the test result
>>> >>>>>> directory. In the synctest example, for instance, my contains:
>>> >>>>>>
>>> >>>>>> $ avocado run examples/tests/synctest.py
>>> >>>>>> $ cat
>>> >>>>>>
>>> ~/avocado/job-results/latest/test-results/1-examples_tests_synctest.py\:SyncTest.test/stdout
>>> >>>>>>
>>> >>>>>>
>>> >>>>>>
>>> >>>>>> PAR : waiting
>>> >>>>>> PASS : sync interrupted
>>> >>>>>>
>>> >>>>>> `stderr` is actually empty for that test:
>>> >>>>>>
>>> >>>>>> $ wc -l
>>> >>>>>>
>>> ~/avocado/job-results/latest/test-results/1-examples_tests_synctest.py\:SyncTest.test/stderr
>>> >>>>>>
>>> >>>>>>
>>> >>>>>> 0
>>> >>>>>>
>>> /home/cleber/avocado/job-results/latest/test-results/1-examples_tests_synctest.py:SyncTest.test/stderr
>>> >>>>>>
>>> >>>>>>
>>> >>>>>>
>>> >>>>>> What you have to do is, once you're satisfied with those outputs,
>>> and
>>> >>>>>> they're considered "the gold standard", you'd move those to the
>>> test
>>> >>>>>> *data directory*.
>>> >>>>>>
>>> >>>>>> So, if you test is hosted at, `/tests/xl.py`, you'd created the
>>> >>>>>> `/tests/xl.py.data`, and put those files there, named
>>> `stdout.expected`
>>> >>>>>> and `stderr.expected`.
>>> >>>>>>
>>> >>>>>> Whenever you run `avocado run --output-check-record all
>>> /tests/xl.py`,
>>> >>>>>> those files will be used and the output of the *current* test
>>> execution
>>> >>>>>> will be compared to those "gold standards".
>>> >>>>>>
>>> >>>>>>> The script is very simple and the way I execute the command is:
>>> >>>>>>>
>>> >>>>>>> cmd = ('/usr/sbin/xl create /VM/guest1/vm.cfg')
>>> >>>>>>> if utils.system(cmd) == "0":
>>> >>
>>> >> The issue seems to be related to the fact that you're using old
>>> autotest
>>> >> libraries to execute your external commands.
>>> >>
>>> >> The output record/check support is built into Avocado's libraries,
>>> >> namely `avocado.utils.process`.
>>> >>
>>> >> Try to replace your code with:
>>> >>
>>> >> from avocado.utils import process
>>> >> ...
>>> >> process.system(cmd)
>>> >>
>>> >> Also, mixing and matching autotest and avocado libraries in the same
>>> >> test code is not something I'd recommend. Not that it's guaranteed to
>>> >> break. I'd recomend to (try to) move to avocado libraries, or keep an
>>> >> eye on strange behavior like this.
>>> >>
>>> >>>>>>> pass
>>> >>>>>>> else:
>>> >>>>>>> return False
>>> >>>>>>>
>>> >>>>>>> The command send to stdout:
>>> >>>>>>>
>>> >>>>>>> Parsing config from /VM/guest1/vm.cfg
>>> >>>>>>>
>>> >>>>>>> I run the test as:
>>> >>>>>>>
>>> >>>>>>> avocado run --output-check-record all xentest.py
>>> >>>>>>>
>>> >>>>>>> The job.log file contains:
>>> >>>>>>>
>>> >>>>>>> 2016-09-07 13:04:48,015 test L0214 INFO | START
>>> >>>>>>>
>>> 1-/root/avocado-vt/io-fs-autotest-xen/xen/tests/xentest.py:xentest.test_xen_start_stop;1
>>> >>>>>>>
>>> >>>>>>>
>>> >>>>>>>
>>> >>>>>>> 2016-09-07 13:04:48,051 xentest L0033 INFO |
>>> >>>>>>>
>>> 1-/root/avocado-vt/io-fs-autotest-xen/xen/tests/xentest.py:xentest.test_xen_start_stop;1:
>>> >>>>>>>
>>> >>>>>>>
>>> >>>>>>> Running action create
>>> >>>>>>> 2016-09-07 13:04:49,067 utils L0151 ERROR| [stderr]
>>> Parsing
>>> >>>>>>> config from /VM/guest1/vm.cfg
>>> >>>>>>> 2016-09-07 13:04:49,523 test L0586 INFO | PASS
>>> >>>>>>>
>>> 1-/root/avocado-vt/io-fs-autotest-xen/xen/tests/xentest.py:xentest.test_xen_start_stop;1
>>> >>>>>>>
>>> >>>>>>>
>>> >>>>>>>
>>> >>>>>>>
>>> >>>>>>> Thanks for your time and help.
>>> >>>>>>
>>> >>>>>> Let me know if it's clear now! And thanks for trying Avocado out!
>>> >>>>>>
>>> >
>>> > --
>>> >
>>> > Regards,
>>> >
>>> > Marcos Eduardo Matsunaga
>>> >
>>> > Oracle USA
>>> > Linux Engineering
>>> >
>>> > “The statements and opinions expressed here are my own and do not
>>> > necessarily represent those of Oracle Corporation.”
>>> >
>>>
>>>
>>> --
>>>
>>> Regards,
>>>
>>> Marcos Eduardo Matsunaga
>>>
>>> Oracle USA
>>> Linux Engineering
>>>
>>> “The statements and opinions expressed here are my own and do not
>>> necessarily represent those of Oracle Corporation.”
>>>
>>>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/avocado-devel/attachments/20160908/68548efb/attachment.htm>
More information about the Avocado-devel
mailing list