CiscoTestAutomation / pyats

Cisco DevNet pyATS Test Framework Bug Tracker
Apache License 2.0
148 stars 31 forks source link

xunit.xml: FIXME: fill this with the [STDOUT|STDERR] of the test run #199

Closed paweln007 closed 7 months ago

paweln007 commented 1 year ago

Passing the --xunit option to latest pyats to have a JUnit report generated:

pyats run job --xunit [job file]

The report does not have system-out and system-error entries populated.

<?xml version="1.0" encoding="UTF-8"?>
<testsuites disabled="0" errors="1" failures="0" tests="27" time="136.51647099999997">
        <testsuite disabled="0" errors="1" failures="0" name="1_smoke-suite" skipped="25" tests="27" time="136.51647099999997">
                <testcase name="001_common_setup" time="129.465092">
                        <error type="error" message="Test errored"> Please see the trade link to view the log: </error>
                        <system-out># FIXME: fill this with the STDOUT of the test run</system-out>
                        <system-err># FIXME: fill this with the STDERR of the test run</system-err>
                </testcase>
                <testcase name="002_NetworkInit" time="0.002119">
                        <skipped type="skipped" message="Test blocked"> Please see the trade link to view the log: </skipped>
                        <system-out># FIXME: fill this with the STDOUT of the test run</system-out>
                        <system-err># FIXME: fill this with the STDERR of the test run</system-err>
                </testcase>
paweln007 commented 1 year ago

Another missing data piece is the text field of , populated here with: Please see the trade link to view the log:

<error type="error" message="Test errored"> Please see the trade link to view the log: </error>

sumitsehgal123 commented 1 year ago

Hi , Thanks for reaching out piestack support team, I will be looking at your ticket and reviewing it . Please make sure add the logs / pyats version / package list .

paweln007 commented 1 year ago
$ pyats version check
You are currently running pyATS version: 22.1
Python: 3.10.0 [64bit]

  Package              Version
  pyats                22.1   
  pyats.aereport       22.1   
  pyats.aetest         22.1   
  pyats.async          22.1   
  pyats.connections    22.1   
  pyats.datastructures 22.1   
  pyats.easypy         22.1   
  pyats.kleenex        22.1   
  pyats.log            22.1   
  pyats.reporter       22.1   
  pyats.results        22.1   
  pyats.tcl            22.1   
  pyats.topology       22.1   
  pyats.utils          22.1   
  unicon               22.1   
  unicon.plugins       22.1.1
$ cat env.txt
Runtime Values
{'argv': {'all': '/usr/local/bin/pyats run job job.py --verbose --no-mail '
                 '--html-logs . --xunit .',
          'custom': ('',)},
 'host': {'architecture': 'x86_64',
          'distro': 'Fedora Linux 35 ',
          'kernel': '5.15.0-1031-azure',
          'name': 'jmp-qainfra-1'},
 'prefix': '/usr',
 'python': {'architecture': '64bit',
            'name': 'cpython',
            'tag': 'cpython-310',
            'version': '3.10.0'},
 'user': 'paweln'}
…
$ cat suite.py 
from pyats import aetest

class CommonSetup(aetest.CommonSetup):
    @aetest.subsection
    def connect_to_devices(self):
        pass

class Testcase0(aetest.Testcase):
    @aetest.test
    def test(self):
        pass

class Testcase1(aetest.Testcase):
    @aetest.test
    def test(self):
        assert 1 + 1 == 3

class Testcase2(aetest.Testcase):
    @aetest.test
    def test(self):
        self.failed('FAILED to veirfy xyz')

class Testcase3(aetest.Testcase):
    @aetest.test
    def test(self):
        self.errored('ERRORED while trying to veirfy xyz')

class CommonCleanup(aetest.CommonCleanup):
    @aetest.subsection
    def disconnect_from_devices(self):
        pass

if __name__ == '__main__':
    aetest.main()
$ cat xunit.xml 
<?xml version="1.0" encoding="UTF-8"?>
<testsuites disabled="0" errors="1" failures="2" tests="6" time="0.06748">
    <testsuite disabled="0" errors="1" failures="2" name="1_suite" skipped="0" tests="6" time="0.06748">
        <testcase name="001_common_setup" time="0.012023">
            <system-out># FIXME: fill this with the STDOUT of the test run</system-out>
            <system-err># FIXME: fill this with the STDERR of the test run</system-err>
        </testcase>
        <testcase name="002_Testcase0" time="0.011385">
            <system-out># FIXME: fill this with the STDOUT of the test run</system-out>
            <system-err># FIXME: fill this with the STDERR of the test run</system-err>
        </testcase>
        <testcase name="003_Testcase1" time="0.010427">
            <failure type="failure" message="Test failed"> Please see the trade link to view the log: </failure>
            <system-out># FIXME: fill this with the STDOUT of the test run</system-out>
            <system-err># FIXME: fill this with the STDERR of the test run</system-err>
        </testcase>
        <testcase name="004_Testcase2" time="0.012274">
            <failure type="failure" message="Test failed"> Please see the trade link to view the log: </failure>
            <system-out># FIXME: fill this with the STDOUT of the test run</system-out>
            <system-err># FIXME: fill this with the STDERR of the test run</system-err>
        </testcase>
        <testcase name="005_Testcase3" time="0.010987">
            <error type="error" message="Test errored"> Please see the trade link to view the log: </error>
            <system-out># FIXME: fill this with the STDOUT of the test run</system-out>
            <system-err># FIXME: fill this with the STDERR of the test run</system-err>
        </testcase>
        <testcase name="006_common_cleanup" time="0.010384">
            <system-out># FIXME: fill this with the STDOUT of the test run</system-out>
            <system-err># FIXME: fill this with the STDERR of the test run</system-err>
        </testcase>
    </testsuite>
</testsuites>
sumitsehgal123 commented 1 year ago

Hi Please can you share the scripts path location to me .

And Please also try the below commands. pyats run job /path/to/jobfile.py --testbed-file /path/to/testbed.yaml pyats run job job.py --verbose --no-mail --html-logs . --xunit

paweln007 commented 1 year ago

Please see my previous comment for the content of the test suite file.

I did not use a test bed file (it's not needed to reproduce the failure). The test job file is as follows:

$ cat job.py 
from pyats.easypy import run

def main():
    run('suite.py')
$
sumitsehgal123 commented 1 year ago

Hi paweln007, I tried from my side its working fine for me . Please find the below logs .

(devat) [sumsehga@sjc-ads-920 workspace]$ pip list Package Version


aiofiles 0.6.0 aiohttp 3.7.2 aiohttp-swagger 1.0.15 ansible 2.9.7 arrow 0.15.5 astroid 2.4.2 async 0.6.2 async-lru 1.0.2 async-timeout 3.0.1 asynctest 0.13.0 atomicwrites 1.4.0 ats 22.1 ats.aereport 22.1 ats.aetest 22.1 ats.async 22.1 ats.cisco 22.1 ats.connections 22.1 ats.datastructures 22.1 ats.easypy 22.1 ats.kleenex 22.1 ats.log 22.1 ats.reporter 22.1 ats.results 22.1 ats.tcl 22.1 ats.topology 22.1 ats.utils 22.1 attrs 20.2.0 backports.ssl 0.0.9 bcrypt 3.2.0 binaryornot 0.4.4 certifi 2020.6.20 cffi 1.14.3 chardet 3.0.4 charset-normalizer 3.0.1 cisco-gnmi 1.0.15 ciscoisesdk 2.0.4 click 7.1.2 cmd2 1.3.11 colorama 0.4.4 commitvalidator 21.12 cookiecutter 1.7.0 coverage 5.3 cryptography 39.0.0 Cython 0.29.21 decorator 4.4.2 deepdiff 5.7.0 dict2xml 1.7.2 dicttoxml 1.7.4 dill 0.3.1.1 distro 1.5.0 docker 4.2.0 docutils 0.19 f5-icontrol-rest 1.3.13 fastjsonschema 2.16.2 fastnumbers 3.1.0 flake8 3.8.3 future 0.18.2 fuzzywuzzy 0.18.0 gitdb 4.0.5 GitPython 3.1.7 grpcio 1.40.0 grpcio-tools 1.40.0 hltapi 22.5 idna 2.10 idna-ssl 1.1.0 importlib-metadata 2.0.0 iniconfig 0.0.0 isort 5.6.4 ixia-tcl 22.5 IxNetwork 9.0.1915.16 ixnetwork-restpy 1.1.1 jenkinsapi 0.3.11 Jinja2 2.11.3 jinja2-time 0.2.0 jsonpickle 1.3 jsonpointer 2.0 jsonschema 3.2.0 junit-xml 1.9 lazy-object-proxy 1.4.3 lxml 4.6.1 MarkupSafe 1.1.1 mccabe 0.6.1 more-itertools 8.5.0 multidict 5.0.0 natsort 7.1.1 ncclient 0.6.9 ndg-httpsclient 0.5.1 netaddr 0.8.0 netifaces 0.11.0 ordered-set 4.1.0 packaging 20.4 paramiko 2.7.2 pathlib2 2.3.5 pathspec 0.7.0 pexpect 4.8.0 pip 23.0.1 pluggy 0.13.1 ply 3.11 poyo 0.5.0 prettytable 3.3.0 protobuf 3.20.0 psutil 5.8.0 ptyprocess 0.7.0 py 1.9.0 pyaml 21.10.1 pyang 2.5.0 pyasn1 0.4.8 pyats-image-builder 23.3 pycodestyle 2.6.0 pycparser 2.20 pycrypto 2.6.1 pycryptodomex 3.9.8 pyflakes 2.2.0 pyftpdlib 1.5.6 PyICU 2.6 pylint 2.3.0 PyMySQL 1.0.2 PyNaCl 1.4.0 pyOpenSSL 23.0.0 pyparsing 2.4.7 pyperclip 1.8.1 pyrsistent 0.17.3 pysmi 0.2.2 pysnmp 4.4.9 PySocks 1.7.1 pytest 0.0.0 python-dateutil 2.8.1 python-engineio 3.13.2 python-socketio 4.6.0 pytz 2020.1 pyvxr 1.2.9 PyYAML 5.3.1 pyzmq 17.1.0 requests 2.28.2 requests-mock 1.8.0 requests-toolbelt 0.9.1 rfc3987 1.3.8 robotframework 3.2.2 ruamel.yaml 0.16.12 ruamel.yaml.clib 0.2.0 scapy 95ba5b8 scp 0.13.3 selenium 3.141.0 setuptools 65.3.0 setuptools-scm 6.4.2 sh 1.14.2 six 1.15.0 smmap 3.0.4 strict-rfc3339 0.7 tabulate 0.8.7 tcl-ats 22.5 tenacity 8.0.1 terminaltables 3.1.0 textfsm 1.1.3 tftpy 0.8.0 timeout-decorator 0.5.0 toml 0.10.1 tomli 2.0.1 tqdm 4.51.0 trex-hltapi 23.2 typing-extensions 3.7.4.3 unicon 22.1.1 unicon.plugins 22.1.1 urllib3 1.25.8 wcwidth 0.2.5 webcolors 1.11.1 websocket-client 0.57.0 websockets 8.1 wheel 0.37.1 whichcraft 0.6.1 wrapt 1.14.1 xlrd 1.2.0 XlsxWriter 1.3.7 xlwt 1.3.0 xmljson 0.2.1 xmltodict 0.12.0 yamllint 1.21.0 yamlordereddictloader 0.4.0 yarl 1.6.2 zipp 3.4.0 (devat) [sumsehga@sjc-ads-920 workspace]$ pyats run job job.py --verbose --no-mail --html-logs . --xunit 2023-04-12T09:35:03: %EASYPY-DEBUG: Creating instance to Reporter Server 2023-04-12T09:35:05: %REPORTER-DEBUG: ReportServer started with pid 2354248. Invoked from pid 2354086. 2023-04-12T09:35:05: %REPORTER-DEBUG: Client (pid: 2354086) trying to connect to Server (socket: /tmp/pyats.2pnt_29r.sock) 2023-04-12T09:35:05: %REPORTER-DEBUG: Client (pid: 2354086, socket: /tmp/pyats.2pnt_29r.sock) is connected to socket at /tmp/pyats.2pnt_29r.sock 2023-04-12T09:35:05: %REPORTER-DEBUG: Client (pid: 2354086, socket: /tmp/pyats.2pnt_29r.sock) is now registered with server 2023-04-12T09:35:05: %REPORTER-DEBUG: Enabled ReportClient auto-reconnect. 2023-04-12T09:35:05: %EASYPY-INFO: Starting job run: job 2023-04-12T09:35:05: %EASYPY-INFO: Runinfo directory: /nobackup/sumsehga/workspace/polaris/binos/linkfarm/sdks-host/iosxe-pyats/nativesdk/sdk/sysroots/x86_64-xesdk-linux/usr/users/sumsehga/runinfo/job.2023Apr12_09:35:03.091171 2023-04-12T09:35:05: %EASYPY-INFO: -------------------------------------------------------------------------------- 2023-04-12T09:35:05: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.logs.LogWarnings object at 0x7fa4ecd7cd90>: pre_job 2023-04-12T09:35:05: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.logs.LogWarnings object at 0x7fa4ecd7cd90>: pre_job 2023-04-12T09:35:05: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.runinfo.RuninfoSymlinkPlugin object at 0x7fa4ec430220>: pre_job 2023-04-12T09:35:05: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.runinfo.RuninfoSymlinkPlugin object at 0x7fa4ec430220>: pre_job 2023-04-12T09:35:05: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.debug.CopyJobfileToRunInfo object at 0x7fa4ec4c6f40>: pre_job 2023-04-12T09:35:05: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.debug.CopyJobfileToRunInfo object at 0x7fa4ec4c6f40>: pre_job 2023-04-12T09:35:05: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.debug.CopyManifestFileToRunInfo object at 0x7fa4ec43f9d0>: pre_job 2023-04-12T09:35:05: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.debug.CopyManifestFileToRunInfo object at 0x7fa4ec43f9d0>: pre_job 2023-04-12T09:35:05: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.logs.LiveviewPlugin object at 0x7fa4ec43fc10>: pre_job 2023-04-12T09:35:05: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.logs.LiveviewPlugin object at 0x7fa4ec43fc10>: pre_job 2023-04-12T09:35:05: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.logs.JobLogPlugin object at 0x7fa4ec43fd00>: pre_job 2023-04-12T09:35:05: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.logs.JobLogPlugin object at 0x7fa4ec43fd00>: pre_job 2023-04-12T09:35:05: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.debug.ArchiveConfigPlugin object at 0x7fa4ec43fdf0>: pre_job 2023-04-12T09:35:05: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.debug.ArchiveConfigPlugin object at 0x7fa4ec43fdf0>: pre_job 2023-04-12T09:35:05: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.testbed.TestbedPlugin object at 0x7fa4ec43fe50>: pre_job 2023-04-12T09:35:05: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.testbed.TestbedPlugin object at 0x7fa4ec43fe50>: pre_job 2023-04-12T09:35:05: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.debug.EnvironmentDebugPlugin object at 0x7fa4ec43fe20>: pre_job 2023-04-12T09:35:07: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.debug.EnvironmentDebugPlugin object at 0x7fa4ec43fe20>: pre_job 2023-04-12T09:35:07: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.kleenex.KleenexPlugin object at 0x7fa4ecff2b50>: pre_job 2023-04-12T09:35:07: %UTILS-DEBUG: parser skipping argument run 2023-04-12T09:35:07: %UTILS-DEBUG: parser skipping argument job 2023-04-12T09:35:07: %UTILS-DEBUG: parser skipping argument job.py 2023-04-12T09:35:07: %UTILS-DEBUG: parser skipping argument run 2023-04-12T09:35:07: %UTILS-DEBUG: parser skipping argument job 2023-04-12T09:35:07: %UTILS-DEBUG: parser skipping argument job.py 2023-04-12T09:35:07: %UTILS-DEBUG: parser skipping argument run 2023-04-12T09:35:07: %UTILS-DEBUG: parser skipping argument job 2023-04-12T09:35:07: %UTILS-DEBUG: parser skipping argument job.py 2023-04-12T09:35:07: %EASYPY-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %EASYPY-INFO: | Clean Information | 2023-04-12T09:35:07: %EASYPY-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %EASYPY-INFO: {'bringup': {}, 'cleaners': {}, 'devices': {}}

2023-04-12T09:35:07: %EASYPY-DEBUG: Skipping dynamic bringup since no logical testbed has been specified. 2023-04-12T09:35:07: %EASYPY-DEBUG: Skipping clean since the -invoke_clean parameter was not specified. 2023-04-12T09:35:07: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.kleenex.KleenexPlugin object at 0x7fa4ecff2b50>: pre_job 2023-04-12T09:35:07: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.runinfo.TaskResultsPlugin object at 0x7fa4ecff2d90>: pre_job 2023-04-12T09:35:07: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.runinfo.TaskResultsPlugin object at 0x7fa4ecff2d90>: pre_job 2023-04-12T09:35:07: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.rerun.RerunPlugin object at 0x7fa4ec4b64f0>: pre_job 2023-04-12T09:35:07: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.rerun.RerunPlugin object at 0x7fa4ec4b64f0>: pre_job 2023-04-12T09:35:07: %EASYPY-DEBUG: Running plugin <pyats.cisco.businesstelemetry.BusinessTelemetryPlugin object at 0x7fa4ec4b6790>: pre_job 2023-04-12T09:35:07: %EASYPY-DEBUG: Finished running plugin <pyats.cisco.businesstelemetry.BusinessTelemetryPlugin object at 0x7fa4ec4b6790>: pre_job 2023-04-12T09:35:07: %EASYPY-DEBUG: Running plugin <pyats.cisco.telemetry.TelemetryPlugin object at 0x7fa4ec4b6160>: pre_job 2023-04-12T09:35:07: %EASYPY-DEBUG: Finished running plugin <pyats.cisco.telemetry.TelemetryPlugin object at 0x7fa4ec4b6160>: pre_job 2023-04-12T09:35:07: %UTILS-DEBUG: Loading: /nobackup/sumsehga/workspace/job.py 2023-04-12T09:35:07: %UTILS-DEBUG: Loaded: <module 'pyats.easypy.jobs.job' from '/nobackup/sumsehga/workspace/job.py'> 2023-04-12T09:35:07: %REPORTER-DEBUG: Client (pid: 2354332, socket: /tmp/pyats.2pnt_29r.sock) trying to connect to Server (socket: /tmp/pyats.2pnt_29r.sock) 2023-04-12T09:35:07: %REPORTER-DEBUG: Client (pid: 2354332, socket: /tmp/pyats.2pnt_29r.sock) is connected to socket at /tmp/pyats.2pnt_29r.sock 2023-04-12T09:35:07: %REPORTER-DEBUG: Client (pid: 2354332, socket: /tmp/pyats.2pnt_29r.sock) is now registered with server 2023-04-12T09:35:07: %UTILS-DEBUG: Resetting SIGINT handler 2023-04-12T09:35:07: %EASYPY-INFO: Starting task execution: Task-1 2023-04-12T09:35:07: %EASYPY-INFO: test harness = pyats.aetest 2023-04-12T09:35:07: %EASYPY-INFO: testscript = /nobackup/sumsehga/workspace/suite.py 2023-04-12T09:35:07: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.logs.JobLogPlugin object at 0x7fa4ec43fd00>: pre_task 2023-04-12T09:35:07: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.logs.JobLogPlugin object at 0x7fa4ec43fd00>: pre_task 2023-04-12T09:35:07: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.logs.TaskLogPlugin object at 0x7fa4ec43fb50>: pre_task 2023-04-12T09:35:07: %LOG-DEBUG: Enabled forked tasklog generation 2023-04-12T09:35:07: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.logs.TaskLogPlugin object at 0x7fa4ec43fb50>: pre_task 2023-04-12T09:35:07: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.kleenex.KleenexPlugin object at 0x7fa4ecff2b50>: pre_task 2023-04-12T09:35:07: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.kleenex.KleenexPlugin object at 0x7fa4ecff2b50>: pre_task 2023-04-12T09:35:07: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.rerun.RerunPlugin object at 0x7fa4ec4b64f0>: pre_task 2023-04-12T09:35:07: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.rerun.RerunPlugin object at 0x7fa4ec4b64f0>: pre_task 2023-04-12T09:35:07: %EASYPY-DEBUG: Running plugin <pyats.cisco.businesstelemetry.BusinessTelemetryPlugin object at 0x7fa4ec4b6790>: pre_task 2023-04-12T09:35:07: %EASYPY-DEBUG: Finished running plugin <pyats.cisco.businesstelemetry.BusinessTelemetryPlugin object at 0x7fa4ec4b6790>: pre_task 2023-04-12T09:35:07: %UTILS-DEBUG: Loading: /nobackup/sumsehga/workspace/suite.py 2023-04-12T09:35:07: %UTILS-DEBUG: Loaded: <module 'pyats.aetest.testscript.suite' from '/nobackup/sumsehga/workspace/suite.py'> 2023-04-12T09:35:07: %UTILS-DEBUG: parser skipping argument run 2023-04-12T09:35:07: %UTILS-DEBUG: parser skipping argument job 2023-04-12T09:35:07: %UTILS-DEBUG: parser skipping argument job.py 2023-04-12T09:35:07: %UTILS-DEBUG: parser skipping argument run 2023-04-12T09:35:07: %UTILS-DEBUG: parser skipping argument job 2023-04-12T09:35:07: %UTILS-DEBUG: parser skipping argument job.py 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: | Starting common setup | 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: | Starting subsection connect_to_devices | 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: The result of subsection connect_to_devices is => PASSED 2023-04-12T09:35:07: %AETEST-INFO: The result of common setup is => PASSED 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: | Starting testcase Testcase0 | 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: | Starting section test | 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: The result of section test is => PASSED 2023-04-12T09:35:07: %AETEST-INFO: The result of testcase Testcase0 is => PASSED 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: | Starting testcase Testcase1 | 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: | Starting section test | 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-WARNING: Caught an assertion failure while executing section test: 2023-04-12T09:35:07: %AETEST-WARNING: Traceback (most recent call last): 2023-04-12T09:35:07: %AETEST-WARNING: File "/nobackup/sumsehga/workspace/suite.py", line 16, in test 2023-04-12T09:35:07: %AETEST-WARNING: assert 1 + 1 == 3 2023-04-12T09:35:07: %AETEST-WARNING: AssertionError 2023-04-12T09:35:07: %AETEST-INFO: The result of section test is => FAILED 2023-04-12T09:35:07: %AETEST-INFO: The result of testcase Testcase1 is => FAILED 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: | Starting testcase Testcase2 | 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: | Starting section test | 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-ERROR: Failed reason: FAILED to veirfy xyz 2023-04-12T09:35:07: %AETEST-INFO: The result of section test is => FAILED 2023-04-12T09:35:07: %AETEST-INFO: The result of testcase Testcase2 is => FAILED 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: | Starting testcase Testcase3 | 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: | Starting section test | 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-ERROR: Errored reason: ERRORED while trying to veirfy xyz 2023-04-12T09:35:07: %AETEST-INFO: The result of section test is => ERRORED 2023-04-12T09:35:07: %AETEST-INFO: The result of testcase Testcase3 is => ERRORED 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: | Starting common cleanup | 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: | Starting subsection disconnect_from_devices | 2023-04-12T09:35:07: %AETEST-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:07: %AETEST-INFO: The result of subsection disconnect_from_devices is => PASSED 2023-04-12T09:35:07: %AETEST-INFO: The result of common cleanup is => PASSED 2023-04-12T09:35:07: %EASYPY-DEBUG: Running plugin <pyats.cisco.businesstelemetry.BusinessTelemetryPlugin object at 0x7fa4ec4b6790>: post_task 2023-04-12T09:35:07: %CISCO-INFO: Start Telemetry - Task 2023-04-12T09:35:07: %CISCO-DEBUG: Start construct task record with dataKey job.2023Apr12_09:35:03.091171_Task-1 2023-04-12T09:35:07: %CISCO-DEBUG: Construct record done 2023-04-12T09:35:07: %EASYPY-DEBUG: Finished running plugin <pyats.cisco.businesstelemetry.BusinessTelemetryPlugin object at 0x7fa4ec4b6790>: post_task 2023-04-12T09:35:07: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.kleenex.KleenexPlugin object at 0x7fa4ecff2b50>: post_task 2023-04-12T09:35:07: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.kleenex.KleenexPlugin object at 0x7fa4ecff2b50>: post_task 2023-04-12T09:35:07: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.logs.TaskLogPlugin object at 0x7fa4ec43fb50>: post_task 2023-04-12T09:35:07: %LOG-DEBUG: Disabled forked tasklog generation 2023-04-12T09:35:07: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.logs.TaskLogPlugin object at 0x7fa4ec43fb50>: post_task 2023-04-12T09:35:07: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.logs.JobLogPlugin object at 0x7fa4ec43fd00>: post_task 2023-04-12T09:35:07: %EASYPY-INFO: TIMS result uploading is not enabled 2023-04-12T09:35:07: %EASYPY-DEBUG: Running plugin <pyats.cisco.telemetry.TelemetryPlugin object at 0x7fa4ec4b6160>: post_job 2023-04-12T09:35:07: %EASYPY-DEBUG: Finished running plugin <pyats.cisco.telemetry.TelemetryPlugin object at 0x7fa4ec4b6160>: post_job 2023-04-12T09:35:07: %EASYPY-DEBUG: Running plugin <pyats.cisco.businesstelemetry.BusinessTelemetryPlugin object at 0x7fa4ec4b6790>: post_job 2023-04-12T09:35:07: %CISCO-INFO: Start Telemetry - Test 2023-04-12T09:35:07: %CISCO-DEBUG: Start looking for host info of sjc-ads-920 2023-04-12T09:35:07: %CLI-DEBUG: [Shell] Running command: grep -i microsoft /proc/sys/kernel/osrelease 2023-04-12T09:35:07: %CLI-DEBUG: [Shell] Running command: /router/bin/servinfo -f "%o %v" 2023-04-12T09:35:07: %CLI-DEBUG: cel 8.0 2023-04-12T09:35:08: %CISCO-DEBUG: Host info ready {'name': 'sjc-ads-920', 'distro': 'Red Hat Enterprise Linux 8.5 Ootpa', 'kernel': '4.18.0-348.12.2.el8_5.x86_64', 'architecture': 'x86_64', 'os_ver_short': 'CEL8', 'os_ver_full': 'cel 8.0', 'site': 'SJC', 'os': 'CEL', 'os_version': '8.0'} 2023-04-12T09:35:08: %CISCO-DEBUG: Start preprocess sdk pkg data 2023-04-12T09:35:08: %CISCO-DEBUG: Start looking for SDK packages 2023-04-12T09:35:08: %CISCO-DEBUG: SDK package info is ready 2023-04-12T09:35:08: %CISCO-DEBUG: Start preprocess import pkg data 2023-04-12T09:35:08: %CISCO-DEBUG: import package info is ready 2023-04-12T09:35:08: %CISCO-DEBUG: Start preprocess tcl data 2023-04-12T09:35:08: %CISCO-DEBUG: Start looking for TCL tree info 2023-04-12T09:35:08: %CISCO-DEBUG: Not in a Tcl environment: teacup does not exist 2023-04-12T09:35:08: %CISCO-DEBUG: Tcl package info is ready 2023-04-12T09:35:08: %CISCO-DEBUG: Start preprocess tcl proc data 2023-04-12T09:35:08: %CISCO-DEBUG: TCL API info is ready 2023-04-12T09:35:08: %CISCO-DEBUG: Start preprocess tcl history data 2023-04-12T09:35:08: %CISCO-DEBUG: TCL API info is ready 2023-04-12T09:35:08: %CISCO-DEBUG: Start preprocess csccon data 2023-04-12T09:35:08: %CISCO-DEBUG: TCL API info is ready 2023-04-12T09:35:08: %CISCO-DEBUG: Start construct main record with dataKey job.2023Apr12_09:35:03.091171 2023-04-12T09:35:08: %CISCO-DEBUG: Construct record done 2023-04-12T09:35:08: %CISCO-DEBUG: Modules / Packages are found by script. 2023-04-12T09:35:08: %CISCO-DEBUG: {'script': {}} 2023-04-12T09:35:08: %CISCO-DEBUG: Posting data to Kafka https://sjc-ddkafka-rest.ciscointernal.com/topics/AjZP39vs7rsE.NG_BUSINESS_TELEMETRY Data size in bytes: 130770 2023-04-12T09:35:08: %URLLIB3-DEBUG: Starting new HTTPS connection (1): sjc-ddkafka-rest.ciscointernal.com:443 2023-04-12T09:35:08: %URLLIB3-DEBUG: https://sjc-ddkafka-rest.ciscointernal.com:443 "POST /topics/AjZP39vs7rsE.NG_BUSINESS_TELEMETRY HTTP/1.1" 200 None 2023-04-12T09:35:08: %CISCO-INFO: Posted data to Kafka returning status code 200 within time 0:00:00.024812 2023-04-12T09:35:08: %EASYPY-DEBUG: Finished running plugin <pyats.cisco.businesstelemetry.BusinessTelemetryPlugin object at 0x7fa4ec4b6790>: post_job 2023-04-12T09:35:08: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.replay.ReplayPlugin object at 0x7fa4ec4b6850>: post_job 2023-04-12T09:35:08: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.replay.ReplayPlugin object at 0x7fa4ec4b6850>: post_job 2023-04-12T09:35:08: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.htmllogs.HTMLLogsPlugin object at 0x7fa4ec4b63a0>: post_job 2023-04-12T09:35:08: %EASYPY-INFO: Generating HTML report file 2023-04-12T09:35:08: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.htmllogs.HTMLLogsPlugin object at 0x7fa4ec4b63a0>: post_job 2023-04-12T09:35:08: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.xunit.XunitPlugin object at 0x7fa4ec4b6f70>: post_job 2023-04-12T09:35:08: %EASYPY-INFO: Generating xUnit report files 2023-04-12T09:35:08: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.xunit.XunitPlugin object at 0x7fa4ec4b6f70>: post_job 2023-04-12T09:35:08: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.rerun.RerunPlugin object at 0x7fa4ec4b64f0>: post_job 2023-04-12T09:35:08: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.rerun.RerunPlugin object at 0x7fa4ec4b64f0>: post_job 2023-04-12T09:35:08: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.runinfo.TaskResultsPlugin object at 0x7fa4ecff2d90>: post_job 2023-04-12T09:35:08: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.runinfo.TaskResultsPlugin object at 0x7fa4ecff2d90>: post_job 2023-04-12T09:35:08: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.kleenex.KleenexPlugin object at 0x7fa4ecff2b50>: post_job 2023-04-12T09:35:08: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.kleenex.KleenexPlugin object at 0x7fa4ecff2b50>: post_job 2023-04-12T09:35:08: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.testbed.TestbedPlugin object at 0x7fa4ec43fe50>: post_job 2023-04-12T09:35:08: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.testbed.TestbedPlugin object at 0x7fa4ec43fe50>: post_job 2023-04-12T09:35:08: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.logs.JobLogPlugin object at 0x7fa4ec43fd00>: post_job 2023-04-12T09:35:08: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.logs.JobLogPlugin object at 0x7fa4ec43fd00>: post_job 2023-04-12T09:35:08: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.logs.LiveviewPlugin object at 0x7fa4ec43fc10>: post_job 2023-04-12T09:35:08: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.logs.LiveviewPlugin object at 0x7fa4ec43fc10>: post_job 2023-04-12T09:35:08: %EASYPY-DEBUG: Running plugin <pyats.easypy.plugins.runinfo.RuninfoSymlinkPlugin object at 0x7fa4ec430220>: post_job 2023-04-12T09:35:08: %EASYPY-DEBUG: Finished running plugin <pyats.easypy.plugins.runinfo.RuninfoSymlinkPlugin object at 0x7fa4ec430220>: post_job 2023-04-12T09:35:08: %EASYPY-INFO: -------------------------------------------------------------------------------- 2023-04-12T09:35:08: %EASYPY-INFO: Job finished. Wrapping up... 2023-04-12T09:35:08: %REPORTER-DEBUG: Disabled ReportClient auto-reconnect. 2023-04-12T09:35:08: %REPORTER-DEBUG: Terminating ReportServer with pid 2354248 2023-04-12T09:35:09: %REPORTER-DEBUG: ReportServer (pid 2354248) is terminated. 2023-04-12T09:35:09: %EASYPY-INFO: Creating archive file: /nobackup/sumsehga/workspace/polaris/binos/linkfarm/sdks-host/iosxe-pyats/nativesdk/sdk/sysroots/x86_64-xesdk-linux/usr/users/sumsehga/archive/23-04/job.2023Apr12_09:35:03.091171.zip 2023-04-12T09:35:09: %EASYPY-INFO: Uploading logs to TRADe... 2023-04-12T09:35:09: %URLLIB3-DEBUG: Starting new HTTPS connection (1): earms-trade.cisco.com:8914 2023-04-12T09:35:09: %URLLIB3-DEBUG: Starting new HTTPS connection (1): ngdevx.cisco.com:443 2023-04-12T09:35:09: %URLLIB3-DEBUG: https://ngdevx.cisco.com:443 "OPTIONS /services/taas/api/v1/upload/results HTTP/1.1" 200 0 2023-04-12T09:35:09: %URLLIB3-DEBUG: Starting new HTTPS connection (1): ngdevx.cisco.com:443 2023-04-12T09:35:09: %URLLIB3-DEBUG: https://ngdevx.cisco.com:443 "POST /services/taas/api/v1/upload/results HTTP/1.1" 201 211 2023-04-12T09:35:09: %CISCO-INFO: Start Telemetry - Archive Log Upload 2023-04-12T09:35:09: %CISCO-DEBUG: Construct record started 2023-04-12T09:35:09: %CISCO-DEBUG: Construct record done 2023-04-12T09:35:09: %CISCO-DEBUG: Posting data to Kafka https://sjc-ddkafka-rest.ciscointernal.com/topics/AjZP39vs7rsE.NG_BUSINESS_TELEMETRY Data size in bytes: 283 2023-04-12T09:35:09: %URLLIB3-DEBUG: Starting new HTTPS connection (1): sjc-ddkafka-rest.ciscointernal.com:443 2023-04-12T09:35:09: %URLLIB3-DEBUG: https://earms-trade.cisco.com:8914 "POST /services/trade/uploadarchive?archive=/nobackup/sumsehga/workspace/polaris/binos/linkfarm/sdks-host/iosxe-pyats/nativesdk/sdk/sysroots/x86_64-xesdk-linux/usr/users/sumsehga/archive/23-04/job.2023Apr12_09:35:03.091171.zip HTTP/1.1" 200 369 2023-04-12T09:35:09: %EASYPY-DEBUG: {"code":200,"status":"PROCESSING","request_id":"earms-trade_51214970-d915-11ed-8db3-b1d8371af3b1","log_view_url":"https://earms-trade.cisco.com/tradeui/logs/details?archive=/nobackup/sumsehga/workspace/polaris/binos/linkfarm/sdks-host/iosxe-pyats/nativesdk/sdk/sysroots/x86_64-xesdk-linux/usr/users/sumsehga/archive/23-04/job.2023Apr12_09:35:03.091171.zip&atstype=ATS"} 2023-04-12T09:35:09: %URLLIB3-DEBUG: https://sjc-ddkafka-rest.ciscointernal.com:443 "POST /topics/AjZP39vs7rsE.NG_BUSINESS_TELEMETRY HTTP/1.1" 200 109 2023-04-12T09:35:09: %CISCO-INFO: Posted data to Kafka returning status code 200 within time 0:00:00.020672 2023-04-12T09:35:09: %EASYPY-INFO: Log Archive uploaded to: https://ngdevx.cisco.com/services/taas/results/0eb9d454-8846-4bd5-90d6-1dd2979c2b06 2023-04-12T09:35:10: %URLLIB3-DEBUG: Starting new HTTPS connection (1): earms-trade.cisco.com:8914 2023-04-12T09:35:10: %URLLIB3-DEBUG: https://earms-trade.cisco.com:8914 "GET /services/trade/archive/poll?request_id=earms-trade_51214970-d915-11ed-8db3-b1d8371af3b1 HTTP/1.1" 200 365 2023-04-12T09:35:10: %EASYPY-DEBUG: {'code': 200, 'status': 'PASSED', 'request_id': 'earms-trade_51214970-d915-11ed-8db3-b1d8371af3b1', 'log_view_url': 'https://earms-trade.cisco.com/tradeui/logs/details?archive=/nobackup/sumsehga/workspace/polaris/binos/linkfarm/sdks-host/iosxe-pyats/nativesdk/sdk/sysroots/x86_64-xesdk-linux/usr/users/sumsehga/archive/23-04/job.2023Apr12_09:35:03.091171.zip&atstype=ATS'} 2023-04-12T09:35:10: %EASYPY-INFO: TRADe upload completed. 2023-04-12T09:35:10: %EASYPY-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:10: %EASYPY-INFO: | TaaS URL | 2023-04-12T09:35:10: %EASYPY-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:10: %EASYPY-INFO: 2023-04-12T09:35:10: %EASYPY-INFO: TaaS Log Viewer 2023-04-12T09:35:10: %EASYPY-INFO: ------------- 2023-04-12T09:35:10: %EASYPY-INFO: https://ngdevx.cisco.com/services/taas/results/0eb9d454-8846-4bd5-90d6-1dd2979c2b06 2023-04-12T09:35:10: %EASYPY-INFO: 2023-04-12T09:35:10: %EASYPY-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:10: %EASYPY-INFO: | TRADe URL | 2023-04-12T09:35:10: %EASYPY-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:10: %EASYPY-INFO: 2023-04-12T09:35:10: %EASYPY-INFO: Result Viewer 2023-04-12T09:35:10: %EASYPY-INFO: ------------- 2023-04-12T09:35:10: %EASYPY-INFO: https://earms-trade.cisco.com/tradeui/logs/details?archive=/nobackup/sumsehga/workspace/polaris/binos/linkfarm/sdks-host/iosxe-pyats/nativesdk/sdk/sysroots/x86_64-xesdk-linux/usr/users/sumsehga/archive/23-04/job.2023Apr12_09:35:03.091171.zip&atstype=ATS 2023-04-12T09:35:10: %EASYPY-INFO: 2023-04-12T09:35:10: %EASYPY-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:10: %EASYPY-INFO: | Easypy Report | 2023-04-12T09:35:10: %EASYPY-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:10: %EASYPY-INFO: pyATS Instance : /nobackup/sumsehga/workspace/polaris/binos/linkfarm/sdks-host/iosxe-pyats/nativesdk/sdk/sysroots/x86_64-xesdk-linux/usr 2023-04-12T09:35:10: %EASYPY-INFO: Python Version : cpython-3.8.5 (64bit) 2023-04-12T09:35:10: %EASYPY-INFO: CLI Arguments : /nobackup/sumsehga/workspace/polaris/binos/linkfarm/sdks-host/iosxe-pyats/nativesdk/sdk/sysroots/x86_64-xesdk-linux/usr/bin/pyats run job job.py --verbose --no-mail --html-logs . --xunit 2023-04-12T09:35:10: %EASYPY-INFO: User : sumsehga 2023-04-12T09:35:10: %EASYPY-INFO: Host Server : sjc-ads-920 2023-04-12T09:35:10: %EASYPY-INFO: Host OS Version : Red Hat Enterprise Linux 8.5 Ootpa (x86_64) 2023-04-12T09:35:10: %EASYPY-INFO: 2023-04-12T09:35:10: %EASYPY-INFO: Job Information 2023-04-12T09:35:10: %EASYPY-INFO: Name : job 2023-04-12T09:35:10: %EASYPY-INFO: Start time : 2023-04-12 09:35:07.276365 2023-04-12T09:35:10: %EASYPY-INFO: Stop time : 2023-04-12 09:35:07.760783 2023-04-12T09:35:10: %EASYPY-INFO: Elapsed time : 0.484418 2023-04-12T09:35:10: %EASYPY-INFO: Archive : /nobackup/sumsehga/workspace/polaris/binos/linkfarm/sdks-host/iosxe-pyats/nativesdk/sdk/sysroots/x86_64-xesdk-linux/usr/users/sumsehga/archive/23-04/job.2023Apr12_09:35:03.091171.zip 2023-04-12T09:35:10: %EASYPY-INFO: 2023-04-12T09:35:10: %EASYPY-INFO: Total Tasks : 1 2023-04-12T09:35:10: %EASYPY-INFO: 2023-04-12T09:35:10: %EASYPY-INFO: Overall Stats 2023-04-12T09:35:10: %EASYPY-INFO: Passed : 3 2023-04-12T09:35:10: %EASYPY-INFO: Passx : 0 2023-04-12T09:35:10: %EASYPY-INFO: Failed : 2 2023-04-12T09:35:10: %EASYPY-INFO: Aborted : 0 2023-04-12T09:35:10: %EASYPY-INFO: Blocked : 0 2023-04-12T09:35:10: %EASYPY-INFO: Skipped : 0 2023-04-12T09:35:10: %EASYPY-INFO: Errored : 1 2023-04-12T09:35:10: %EASYPY-INFO: 2023-04-12T09:35:10: %EASYPY-INFO: TOTAL : 6 2023-04-12T09:35:10: %EASYPY-INFO: 2023-04-12T09:35:10: %EASYPY-INFO: Success Rate : 50.00 % 2023-04-12T09:35:10: %EASYPY-INFO: 2023-04-12T09:35:10: %EASYPY-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:10: %EASYPY-INFO: | Task Result Summary | 2023-04-12T09:35:10: %EASYPY-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:10: %EASYPY-INFO: Task-1: suite.common_setup PASSED 2023-04-12T09:35:10: %EASYPY-INFO: Task-1: suite.Testcase0 PASSED 2023-04-12T09:35:10: %EASYPY-INFO: Task-1: suite.Testcase1 FAILED 2023-04-12T09:35:10: %EASYPY-INFO: Task-1: suite.Testcase2 FAILED 2023-04-12T09:35:10: %EASYPY-INFO: Task-1: suite.Testcase3 ERRORED 2023-04-12T09:35:10: %EASYPY-INFO: Task-1: suite.common_cleanup PASSED 2023-04-12T09:35:10: %EASYPY-INFO: 2023-04-12T09:35:10: %EASYPY-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:10: %EASYPY-INFO: | Task Result Details | 2023-04-12T09:35:10: %EASYPY-INFO: +------------------------------------------------------------------------------+ 2023-04-12T09:35:10: %EASYPY-INFO: Task-1: suite 2023-04-12T09:35:10: %EASYPY-INFO: |-- common_setup PASSED 2023-04-12T09:35:10: %EASYPY-INFO: | -- connect_to_devices PASSED 2023-04-12T09:35:10: %EASYPY-INFO: |-- Testcase0 PASSED 2023-04-12T09:35:10: %EASYPY-INFO: |-- test PASSED 2023-04-12T09:35:10: %EASYPY-INFO: |-- Testcase1 FAILED 2023-04-12T09:35:10: %EASYPY-INFO: | -- test FAILED 2023-04-12T09:35:10: %EASYPY-INFO: |-- Testcase2 FAILED 2023-04-12T09:35:10: %EASYPY-INFO: |-- test FAILED 2023-04-12T09:35:10: %EASYPY-INFO: |-- Testcase3 ERRORED 2023-04-12T09:35:10: %EASYPY-INFO: | -- test ERRORED 2023-04-12T09:35:10: %EASYPY-INFO:-- common_cleanup PASSED 2023-04-12T09:35:10: %EASYPY-INFO: `-- disconnect_from_devices PASSED 2023-04-12T09:35:10: %EASYPY-DEBUG: Cleaning up the environment ... 2023-04-12T09:35:10: %EASYPY-DEBUG: ... done cleanup! 2023-04-12T09:35:10: %EASYPY-INFO: Done!

Pro Tip

Try the following command to view your logs: pyats logs view

paweln007 commented 1 year ago

The issue has to do with the xunit.xml report. Can you please post its contents as well?

sumitsehgal123 commented 1 year ago

Hi Paweln007, I am working on the above issue and get back to you .

sumitsehgal123 commented 1 year ago

Hi Hi Paweln007, I went through the above issue, and I found that you are not connected to any actual devices . So that the test cases is not able capture or in initial test xunit .Let me know if I can close this issue or you need any other help from our side .

paweln007 commented 1 year ago

Here's a test suite which both prints on the stdout and connects to a device. I used example mock test bed file and test script posted here: https://pubhub.devnetcloud.com/media/pyats-getting-started/docs/_downloads/04c1c0ffd3a875e85db16c7408c0f784/mock.zip

The suite file:

$ cat suite.py 
from pyats import aetest
from genie.testbed import load

class Testcase(aetest.Testcase):

    @aetest.test
    def test(self):
        tb = load('mock.yaml')
        dev = tb.devices['nx-osv-1']
        dev.connect()
        p1 = dev.parse('show inventory')
        serial_number = p1['name']['Slot 1']['serial_number']
        print(f'My serial for slot1 is: {serial_number}')
        self.errored(f'Expected: 123456 but got: {serial_number}')

if __name__ == '__main__':
    aetest.main()

Command:

$ pyats run job job.py --xunit /tmp

Produces:

$ cat /tmp/xunit.xml 
<?xml version="1.0" encoding="UTF-8"?>
<testsuites disabled="0" errors="1" failures="0" tests="1" time="3.840489">
    <testsuite disabled="0" errors="1" failures="0" name="1_suite" skipped="0" tests="1" time="3.840489">
        <testcase name="001_Testcase" time="3.840489">
            <error type="error" message="Test errored"> Please see the trade link to view the log: </error>
            <system-out># FIXME: fill this with the STDOUT of the test run</system-out>
            <system-err># FIXME: fill this with the STDERR of the test run</system-err>
        </testcase>
    </testsuite>
</testsuites>
$

Relevant section of stdout

2023-05-01 19:18:49,249: %UNICON-INFO: +++ nx-osv-1 with via 'ssh': executing command 'show inventory' +++
show inventory
NAME: "Chassis",  DESCR: "NX-OSv Chassis "                       
PID: N7K-C7018           ,  VID: V00 ,  SN: TB00010000B          

NAME: "Slot 1",  DESCR: "NX-OSv Supervisor Module"              
PID: N7K-SUP1            ,  VID: V00 ,  SN: TM00010000B          

NAME: "Slot 2",  DESCR: "NX-OSv Ethernet Module"                
PID: N7K-F248XP-25       ,  VID: V00 ,  SN: TM00010000C          

NAME: "Slot 3",  DESCR: "NX-OSv Ethernet Module"                
PID: N7K-F248XP-25       ,  VID: V00 ,  SN: TM00010000D          

NAME: "Slot 4",  DESCR: "NX-OSv Ethernet Module"                
PID: N7K-F248XP-25       ,  VID: V00 ,  SN: TM00010000E          

NAME: "Slot 33",  DESCR: "NX-OSv Chassis Power Supply"           
PID:                     ,  VID: V00 ,  SN:                      

NAME: "Slot 35",  DESCR: "NX-OSv Chassis Fan Module"             
PID:                     ,  VID: V00 ,  SN:
switch#
My serial for slot1 is: TM00010000B
2023-05-01T19:18:49: %AETEST-ERROR: Errored reason: Expected: 123456 but got: TM00010000B
2023-05-01T19:18:49: %AETEST-INFO: The result of section test is => ERRORED
2023-05-01T19:18:49: %AETEST-INFO: The result of testcase Testcase is => ERRORED
2023-05-01T19:18:49: %EASYPY-INFO: Generating xUnit report files

I am on pyats version 23.4

sumitsehgal123 commented 1 year ago

Hi , I am working on it . and get back to you .

sumitsehgal123 commented 1 year ago

Currently the development related discussion is going on with the team. Once it is done, I'll start working on it.

paweln007 commented 10 months ago

I have not received any updates on this item.

-Pawel

On Oct 16, 2023, at 9:20 PM, Suchv123 @.***> wrote:

@paweln007 https://github.com/paweln007 did you get to know the solution for the above issue you have mentioned?

— Reply to this email directly, view it on GitHub https://github.com/CiscoTestAutomation/pyats/issues/199#issuecomment-1765505102, or unsubscribe https://github.com/notifications/unsubscribe-auth/AFIJEJGRKOH6KTSNUOVFKBLX7XMNVAVCNFSM6AAAAAAUJYNMDGVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTONRVGUYDKMJQGI. You are receiving this because you were mentioned.

sumitsehgal123 commented 10 months ago

Hi , I am working on your issue , and PR has been raised ,Working on unit test file .Once the PR has been merged and issue has been fix .I will informed you .

davidwallis commented 8 months ago

Any updates on this?

SohanTirpude commented 7 months ago

Hello @paweln007 and @davidwallis3101,

We added the fix for this issue and in the version of 24.2 this fix will be available. Meanwhile, each testcases' all stdout will be available in the system-out of each testcases in xunit.xml file.

For example, this is how it will look like:

<?xml version="1.0" encoding="UTF-8"?>
<testsuites disabled="0" errors="1" failures="0" tests="1" time="7.648091">
    <testsuite disabled="0" errors="1" failures="0" name="1_suite" skipped="0" tests="1" time="7.648091">
        <testcase name="001_Testcase" time="7.648091">
            <system-out>3: bgl-ads-6256: 2024-01-18T16:25:42: %AETEST-6-INFO: %[part=3.1/3][pid=2210693][pname=Task-1]: +------------------------------------------------------------------------------+
4: bgl-ads-6256: 2024-01-18T16:25:42: %AETEST-6-INFO: %[part=3.2/3][pid=2210693][pname=Task-1]: |                          Starting testcase Testcase                          |
5: bgl-ads-6256: 2024-01-18T16:25:42: %AETEST-6-INFO: %[part=3.3/3][pid=2210693][pname=Task-1]: +------------------------------------------------------------------------------+
6: bgl-ads-6256: 2024-01-18T16:25:42: %AETEST-6-INFO: %[part=6.1/3][pid=2210693][pname=Task-1]: +------------------------------------------------------------------------------+
7: bgl-ads-6256: 2024-01-18T16:25:42: %AETEST-6-INFO: %[part=6.2/3][pid=2210693][pname=Task-1]: |                            Starting section test                             |
8: bgl-ads-6256: 2024-01-18T16:25:42: %AETEST-6-INFO: %[part=6.3/3][pid=2210693][pname=Task-1]: +------------------------------------------------------------------------------+
9: bgl-ads-6256: 2024-01-18T16:25:42: %UNICON-6-INFO: %[pid=2210693][pname=Task-1]: +++ nx-osv-1 logfile /xxxx/users/x/runinfo/job.2024Jan18_16:25:35.571835/nx-osv-1-cli-1705575342.log +++
10: bgl-ads-6256: 2024-01-18T16:25:42: %UNICON-6-INFO: %[pid=2210693][pname=Task-1]: +++ Unicon plugin nxos (unicon.internal.plugins.nxos) +++
11: bgl-ads-6256: 2024-01-18T16:25:42: %WARNINGS-4-WARNING: %[part=11.1/3][pid=2210693][pname=Task-1]: /xxxx/lib/python3.8/site-packages/unicon/bases/routers/connection.py:97:
12: bgl-ads-6256: 2024-01-18T16:25:42: %WARNINGS-4-WARNING: %[part=11.2/3][pid=2210693][pname=Task-1]: DeprecationWarning: Arguments 'username', 'enable_password','tacacs_password' and 'line_password' are now deprecated and replaced by 'credentials'.
13: bgl-ads-6256: 2024-01-18T16:25:42: %WARNINGS-4-WARNING: %[part=11.3/3][pid=2210693][pname=Task-1]:   warnings.warn(message = &quot;Arguments 'username', &quot;
Trying mock_device ...
Connected to mock_device.
Escape character is '^]'.

15: bgl-ads-6256: 2024-01-18T16:25:45: %UNICON-6-INFO: %[pid=2210693][pname=Task-1]: +++ connection to spawn: mock_device_cli --os nxos --mock_data_dir mocked_data/nxos --state connect, id: 140703963845968 +++
16: bgl-ads-6256: 2024-01-18T16:25:45: %UNICON-6-INFO: %[pid=2210693][pname=Task-1]: connection to nx-osv-1

switch#
18: bgl-ads-6256: 2024-01-18T16:25:46: %UNICON-4-WARNING: %[pid=2210693][pname=Task-1]: Invalid hostname detected: found switch, expected nx-osv-1
19: bgl-ads-6256: 2024-01-18T16:25:46: %UNICON-6-INFO: %[pid=2210693][pname=Task-1]: +++ initializing handle +++
20: bgl-ads-6256: 2024-01-18T16:25:46: %UNICON-6-INFO: %[pid=2210693][pname=Task-1]: +++ nx-osv-1 with via 'ssh': executing command 'term length 0' +++
term length 0
switch#
22: bgl-ads-6256: 2024-01-18T16:25:46: %UNICON-6-INFO: %[pid=2210693][pname=Task-1]: +++ nx-osv-1 with via 'ssh': executing command 'term width 511' +++
term width 511
switch#
24: bgl-ads-6256: 2024-01-18T16:25:46: %UNICON-6-INFO: %[pid=2210693][pname=Task-1]: +++ nx-osv-1 with via 'ssh': executing command 'terminal session-timeout 0' +++
terminal session-timeout 0
switch#
26: bgl-ads-6256: 2024-01-18T16:25:46: %UNICON-6-INFO: %[pid=2210693][pname=Task-1]: +++ nx-osv-1(uut) with via 'ssh': configure +++
config term
switch(config)#no logging console
switch(config)#line console
switch(config)#exec-timeout 0
switch(config)#line vty
switch(config)#exec-timeout 0
switch(config)#terminal width 511
switch(config)#end
switch#
36: bgl-ads-6256: 2024-01-18T16:25:49: %UNICON-6-INFO: %[pid=2210693][pname=Task-1]: +++ nx-osv-1 with via 'ssh': executing command 'show inventory' +++
show inventory
NAME: &quot;Chassis&quot;,  DESCR: &quot;NX-OSv Chassis &quot;                       
PID: N7K-C7018           ,  VID: V00 ,  SN: TB00010000B          

NAME: &quot;Slot 1&quot;,  DESCR: &quot;NX-OSv Supervisor Module&quot;              
PID: N7K-SUP1            ,  VID: V00 ,  SN: TM00010000B          

NAME: &quot;Slot 2&quot;,  DESCR: &quot;NX-OSv Ethernet Module&quot;                
PID: N7K-F248XP-25       ,  VID: V00 ,  SN: TM00010000C          

NAME: &quot;Slot 3&quot;,  DESCR: &quot;NX-OSv Ethernet Module&quot;                
PID: N7K-F248XP-25       ,  VID: V00 ,  SN: TM00010000D          

NAME: &quot;Slot 4&quot;,  DESCR: &quot;NX-OSv Ethernet Module&quot;                
PID: N7K-F248XP-25       ,  VID: V00 ,  SN: TM00010000E          

NAME: &quot;Slot 33&quot;,  DESCR: &quot;NX-OSv Chassis Power Supply&quot;           
PID:                     ,  VID: V00 ,  SN:                      

NAME: &quot;Slot 35&quot;,  DESCR: &quot;NX-OSv Chassis Fan Module&quot;             
PID:                     ,  VID: V00 ,  SN:
switch#
38: bgl-ads-6256: 2024-01-18T16:25:49: %AETEST-3-ERROR: %[pid=2210693][pname=Task-1]: Errored reason: Expected: 123456 but got: TM00010000B
39: bgl-ads-6256: 2024-01-18T16:25:49: %AETEST-6-INFO: %[pid=2210693][pname=Task-1]: The result of section test is =&gt; ERRORED
40: bgl-ads-6256: 2024-01-18T16:25:49: %AETEST-6-INFO: %[pid=2210693][pname=Task-1]: The result of testcase Testcase is =&gt; ERRORED
41: bgl-ads-6256: 2024-01-18T16:25:4</system-out>
            <system-err># FIXME: fill this with the STDERR of the test run</system-err>
        </testcase>
    </testsuite>
</testsuites>

Kindly give it a try once pyATS 24.2 version is released. Meanwhile, I am closing this issue. Kindly feel free to re-open it if you have any issues related to it.

Thank you.