[Fuego] [PATCH 13/14] Improve logging
Guilherme Camargo
guicc at profusion.mobi
Thu Apr 26 13:11:14 UTC 2018
On Wed, Apr 25, 2018 at 8:38 PM, <Tim.Bird at sony.com> wrote:
> Can we wrapper LOGGER.info and/or LOGGER.error, to have them emit something
> like a testcase number (or better yet, number and description), so we can
> convert
> some of these to individual testcase outputs?
>
I like the idea. We can do that.
>
> What do you think?
> -- Tim
>
> > -----Original Message-----
> > From: fuego-bounces at lists.linuxfoundation.org [mailto:fuego-
> > bounces at lists.linuxfoundation.org] On Behalf Of Guilherme Campos
> > Camargo
> > Sent: Tuesday, April 24, 2018 10:25 AM
> > To: fuego at lists.linuxfoundation.org
> > Subject: [Fuego] [PATCH 13/14] Improve logging
> >
> > Use LOGGER.info for the messages that are required to identify which
> > tests are running and if they passed.
> >
> > Use Logger.error for test failures.
> >
> > Use Logger.debug for additional information that may be useful while
> > debugging the tests' execution.
> >
> > Signed-off-by: Guilherme Campos Camargo <guicc at profusion.mobi>
> > ---
> > .../Functional.fuego_release_test/test_run.py | 81 +++++++++++--------
> > 1 file changed, 49 insertions(+), 32 deletions(-)
> >
> > diff --git a/engine/tests/Functional.fuego_release_test/test_run.py
> > b/engine/tests/Functional.fuego_release_test/test_run.py
> > index a36014d..0fe9260 100755
> > --- a/engine/tests/Functional.fuego_release_test/test_run.py
> > +++ b/engine/tests/Functional.fuego_release_test/test_run.py
> > @@ -52,8 +52,8 @@ class SeleniumCommand:
> > def exec(self, selenium_ctx):
> > self.driver = selenium_ctx.driver
> > self.driver.refresh()
> > - LOGGER.debug("Executing Selenium Command '%s'",
> > - self.__class__.__name__)
> > + LOGGER.info("Executing Selenium Command '%s'",
> > + self.__class__.__name__)
> >
> > @staticmethod
> > def check_element_text(element, text):
> > @@ -62,11 +62,13 @@ class SeleniumCommand:
> > LOGGER.\
> > debug(" Text '%s' matches element.text '%s'",
> > text, element.text)
> > + LOGGER.info(" Matching text found")
> > return True
> > else:
> > LOGGER.\
> > debug(" Text '%s' does not match element.text
> '%s'",
> > text, element.text)
> > + LOGGER.error(" Matching text not found.")
> > return False
> > except (selenium_exceptions.ElementNotVisibleException,
> > selenium_exceptions.NoSuchAttributeException,):
> > @@ -77,7 +79,7 @@ class SeleniumCommand:
> > def click_element(element):
> > try:
> > element.click()
> > - LOGGER.debug(" Element clicked")
> > + LOGGER.info(" Element clicked")
> > return True
> > except (selenium_exceptions.ElementClickInterceptedException,
> > selenium_exceptions.ElementNotVisibleException,):
> > @@ -124,17 +126,17 @@ class Visit(SeleniumCommand):
> > def exec(self, selenium_ctx):
> > super().exec(selenium_ctx)
> >
> > - LOGGER.debug(" Visiting '%s'", self.url)
> > + LOGGER.info(" Visiting '%s'", self.url)
> > self.driver.get(self.url)
> >
> > r = requests.get(self.url)
> > if r.status_code != self.expected_result:
> > - LOGGER.debug(" HTTP Status Code '%s' is different " +
> > + LOGGER.error(" HTTP Status Code '%s' is different " +
> > "from the expected '%s'", r.status_cod,
> self.url)
> > return False
> >
> > - LOGGER.debug(" HTTP Status Code is same as expected '%s'",
> > - r.status_code)
> > + LOGGER.info(" HTTP Status Code is same as expected '%s'",
> > + r.status_code)
> > return True
> >
> >
> > @@ -280,21 +282,21 @@ class CheckScreenshot(SeleniumCommand):
> > result = RESULTS_REGEX.search(stderr)
> >
> > if not result:
> > - LOGGER.error(" Error processing the output.")
> > + LOGGER.error(" Error processing the output")
> > return False
> >
> > difference = float(result.group(1))
> > if difference > threshold:
> > - LOGGER.debug(" Resulting difference (%s) above threshold
> (%s). ",
> > + LOGGER.error(" Resulting difference (%s) above threshold
> (%s)",
> > difference, threshold)
> > - LOGGER.debug(" Element's screenshot does not match the
> > reference."
> > + LOGGER.error(" Element's screenshot does not match the
> > reference."
> > " See %s for a visual representation of the "
> > " differences.", diff_img_path)
> > return False
> >
> > - LOGGER.debug(" Resulting difference (%s) below threshold
> (%s).",
> > - difference, threshold)
> > - LOGGER.debug(" Element's screenshot matches the reference.")
> > + LOGGER.info(" Resulting difference (%s) below threshold (%s)",
> > + difference, threshold)
> > + LOGGER.info(" Element's screenshot matches the reference")
> > return True
> >
> > def exec(self, selenium_ctx):
> > @@ -354,8 +356,8 @@ class Back(SeleniumCommand):
> > def exec(self, selenium_ctx):
> > super().exec(selenium_ctx)
> >
> > - LOGGER.debug(" Going back")
> > self.driver.back()
> > + LOGGER.info(" Went back")
> >
> > return True
> >
> > @@ -378,7 +380,7 @@ class ShExpect():
> > def exec(self, pexpect_ctx):
> > self.client = pexpect_ctx.client
> >
> > - LOGGER.debug("Executing command '%s'", self.cmd)
> > + LOGGER.info("Executing command '%s'", self.cmd)
> > try:
> > self.client.sendline('%s=$(%s 2>&1)' %
> > (self.OUTPUT_VARIABLE, self.cmd))
> > @@ -413,6 +415,9 @@ class ShExpect():
> > except pexpect.exceptions.EOF:
> > LOGGER.error("Lost connection with docker. Aborting")
> > return False
> > +
> > + LOGGER.info(" Command result and command output matches " +
> > + "the expected result. (Return code: %d)", result)
> > return True
> >
> >
> > @@ -428,10 +433,10 @@ class FuegoContainer:
> > def delete(self):
> > if self.container:
> > if self.rm_after_test:
> > - LOGGER.debug("Removing Container")
> > + LOGGER.info("Removing Container")
> > self.container.remove(force=True)
> > else:
> > - LOGGER.debug("Not Removing the test container")
> > + LOGGER.info("Not Removing the test container")
> >
> > def install(self):
> > self.docker_client = docker.APIClient()
> > @@ -476,22 +481,25 @@ class FuegoContainer:
> > mount['source'] = None
> >
> > cmd = './%s %s' % (self.install_script, self.image_name)
> > - LOGGER.debug("Running '%s' to install the docker image. " +
> > - "This may take a while....", cmd)
> > + LOGGER.info("Running '%s' to install the docker image. " +
> > + "This may take a while....", cmd)
> > status = subprocess.call(cmd, shell=True)
> >
> > LOGGER.debug("Install output code: %s", status)
> >
> > if status != 0:
> > + LOGGER.error("Installation Failed")
> > return None
> >
> > + LOGGER.info("Installation Complete")
> > + LOGGER.info("Creating the container '%s'..." %
> self.container_name)
> > +
> > docker_client = docker.from_env()
> > containers = docker_client.containers.list(
> > all=True, filters={'name': self.container_name})
> > if containers:
> > - LOGGER.debug(
> > - "Erasing the container '%s', so a new one can be
> created",
> > - self.container_name)
> > + LOGGER.debug("Container already exists. Removing it, so a
> new " +
> > + "one can be created")
> > containers[0].remove(force=True)
> >
> > mounts = [
> > @@ -530,7 +538,7 @@ class FuegoContainer:
> > for m in mounts],
> > name=self.container_name, command='/bin/bash')
> >
> > - LOGGER.debug("Container '%s' created", self.container_name)
> > + LOGGER.info("Container '%s' successfully created",
> > self.container_name)
> > return container
> >
> > def is_running(self):
> > @@ -584,14 +592,16 @@ class PexpectContainerSession():
> > self.timeout = timeout
> >
> > def start(self):
> > - LOGGER.debug(
> > - "Starting container '%s'", self.container.container_name)
> > + LOGGER.info(
> > + "Starting container '%s'...", self.container.container_name)
> > self.client = pexpect.spawnu(
> > '%s %s' % (self.start_script, self.container.container_name)
> ,
> > echo=False, timeout=self.timeout)
> >
> > PexpectContainerSession.set_ps1(self.client)
> >
> > + LOGGER.info("Container started with the ip '%s'",
> > + self.container.get_ip())
> > if not self.wait_for_jenkins():
> > return False
> >
> > @@ -629,14 +639,13 @@ class PexpectContainerSession():
> > container_addr = self.container.get_ip()
> > if container_addr is None:
> > return False
> > - LOGGER.debug("Trying to reach jenkins at container '%s' via " +
> > - "the container's IP '%s' at port '%d'",
> > - self.container.container_name,
> > - container_addr, self.container.jenkins_port)
> > + LOGGER.info("Waiting for jenkins on '%s:%d'...",
> > + container_addr, self.container.jenkins_port)
> > if not loop_until_timeout(ping_jenkins, timeout=60):
> > LOGGER.error("Could not connect to jenkins")
> > return False
> >
> > + LOGGER.info("Jenkins is running")
> > return True
> >
> >
> > @@ -649,6 +658,7 @@ class SeleniumContainerSession():
> > self.viewport_height = viewport_height
> >
> > def start(self):
> > + LOGGER.info("Starting a Selenium Session on %s...",
> self.root_url)
> > options = webdriver.ChromeOptions()
> > options.add_argument('headless')
> > options.add_argument('no-sandbox')
> > @@ -662,7 +672,7 @@ class SeleniumContainerSession():
> >
> > self.driver.get(self.root_url)
> >
> > - LOGGER.debug("Started a Selenium Session on %s", self.root_url)
> > + LOGGER.info("Selenium Session started successfully")
> > return True
> >
> > def __del__(self):
> > @@ -696,7 +706,7 @@ def main():
> > return abs_install_dir, abs_working_dir
> >
> > def execute_tests(timeout):
> > - LOGGER.debug("Starting tests")
> > + LOGGER.info("Starting tests...")
> >
> > ctx_mapper = {
> > ShExpect: pexpect_session,
> > @@ -709,10 +719,14 @@ def main():
> > if isinstance(cmd, base_class):
> > if not cmd.exec(ctx):
> > tests_ok = False
> > + LOGGER.error(" FAIL")
> > break
> > + LOGGER.info(" PASS")
> >
> > if tests_ok:
> > - LOGGER.debug("Tests finished.")
> > + LOGGER.info("All tests finished with SUCCESS")
> > + else:
> > + LOGGER.info("Tests finished with ERRORS")
> >
> > return tests_ok
> >
> > @@ -770,11 +784,14 @@ def main():
> > pexpect_session = PexpectContainerSession(container,
> args.start_script,
> > args.timeout)
> > if not pexpect_session.start():
> > + LOGGER.error("Pexpect session failed to start")
> > return 1
> >
> > selenium_session = SeleniumContainerSession(container,
> > viewport_width=1920,
> > viewport_height=1080)
> > +
> > if not selenium_session.start():
> > + LOGGER.error("Selenium session failed to start")
> > return 1
> >
> > if os.getcwd != args.working_dir:
> > --
> > 2.17.0
> >
> > _______________________________________________
> > Fuego mailing list
> > Fuego at lists.linuxfoundation.org
> > https://lists.linuxfoundation.org/mailman/listinfo/fuego
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.linuxfoundation.org/pipermail/fuego/attachments/20180426/b2b067e2/attachment-0001.html>
More information about the Fuego
mailing list