[Fuego] [PATCH 13/14] Improve logging
Tim.Bird at sony.com
Tim.Bird at sony.com
Wed Apr 25 23:38:59 UTC 2018
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?
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
More information about the Fuego
mailing list