Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Create individual log files for each (distro, test suite) pair #2731

Merged
merged 4 commits into from
Jan 18, 2023

Conversation

narrieta
Copy link
Member

Now we create separate log files for each pair of (distro, test suite).

Test suites are executed concurrently on different threads. These changes include a thread-safe logging.Handler that multiplexes log output to the proper file. When writing multi-threaded tests a little extra setup is needed; I'll document that in the wiki and go over the documentation with the team.

@codecov
Copy link

codecov bot commented Jan 17, 2023

Codecov Report

Merging #2731 (34f7376) into develop (abf4161) will not change coverage.
The diff coverage is n/a.

@@           Coverage Diff            @@
##           develop    #2731   +/-   ##
========================================
  Coverage    72.04%   72.04%           
========================================
  Files          104      104           
  Lines        15832    15832           
  Branches      2265     2265           
========================================
  Hits         11406    11406           
  Misses        3912     3912           
  Partials       514      514           

Help us with your feedback. Take ten seconds to tell us how you rate us. Have a feature suggestion? Share it here.

from tests_e2e.scenarios.lib.logging import log as agent_test_logger # Logger used by the tests


def _initialize_lisa_logger():
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Previously this was done in tests_e2e/scenarions/lib/logging.py as part of the setup for the global logger. Since now I separated the LISA log from the test logs, I moved this to this module, which is our interface with LISA.

self.__context.node = node
self.__context.suite_name = f"{self._metadata.full_name}:{runbook.marketplace.offer}-{runbook.marketplace.sku}"
self.__context.suite_name = f"{self._metadata.full_name}_{runbook.marketplace.offer}-{runbook.marketplace.sku}"
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

'-' instead of ':' is friendlier for file names

Returns a reference to the LISA Logger.
"""
return self.context.log

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

self._log is the LISA Logger, while agent_test_logger is the global test Logger (which redirects output to the log file for each suite)

thread_name = current_thread().name
current_thread().name = self.context.suite_name

# We create a separate log file for the test suite.
suite_log_file: Path = Path.home()/'logs'/f"{self.context.suite_name}.log"
agent_test_logger.set_current_thread_log(suite_log_file)
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This sets the log file for the current suite

# Now start the runbook
#
lisa_logs="$HOME/logs/lisa"
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Since now we have multiple logs for the full test run, I moved the LISA logs to their own subdirectory. The main LISA log is directly under this subdirectory.

@@ -0,0 +1,32 @@
#!/usr/bin/env python3
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We have similar tests in DCR. They are very useful when debugging issues in the test pipeline.

maddieford
maddieford previously approved these changes Jan 17, 2023
self.default_handler.setFormatter(self.formatter)
self.per_thread_handlers: Dict[int, FileHandler] = {}

def set_thread_log(self, thread_ident: int, log_file: Path) -> None:
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

How is the thread_ident determined?

Copy link
Member Author

@narrieta narrieta Jan 17, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It is a property of Python's Thread objects.

This method is meant to be used by tests that start multiple threads (currently we don't have many of those) and want the child threads to write to the test's log file. The parent thread would create a new Thread, set the log file using Thread.ident and then start the child thread with Thread.start(). The child thread should call close_current_thread_log() when it completes. I'll document this protocol in the wiki.

Note that _AgentLoggingHandler is not a public class and is not meant to be used outside this module; it is simply an implementation detail of the AgentLogger. Users of the logger would call set_thread_log(), etc on the logger, which simply forwards to the _AgentLoggingHandler.

for r in results:
log.info("\t%s", r)
log.info("")
agent_test_logger.info("\t%s", r)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

why not added to main log? we know the summary in the main log too?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

it doesn't help there. it's a multi-line report and the output from different threads makes it hard to read, plus it won't always be at the end of the log, it'll be lost with the execution for other distros.

while executing the test suite, the purpose of the main log is just to show the progress of the test suite run. i duplicated test errors in the main log because that may be more convenient when checking the overall status of the test run.

@narrieta narrieta merged commit 4b8fe5e into Azure:develop Jan 18, 2023
@narrieta narrieta deleted the test-logs branch January 18, 2023 23:37
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants