diff options
| -rw-r--r-- | tests/frontend/logging.py | 111 | ||||
| -rw-r--r-- | tests/frontend/logging/elements/bar.bst | 4 | ||||
| -rw-r--r-- | tests/frontend/logging/elements/foo.bst | 4 | ||||
| -rw-r--r-- | tests/frontend/logging/elements/logtest.bst | 5 | ||||
| -rw-r--r-- | tests/frontend/logging/files/bar | 0 | ||||
| -rw-r--r-- | tests/frontend/logging/files/foo | 0 | ||||
| -rw-r--r-- | tests/frontend/logging/plugins/logtest.py | 44 | ||||
| -rw-r--r-- | tests/frontend/logging/project.conf | 10 |
8 files changed, 174 insertions, 4 deletions
diff --git a/tests/frontend/logging.py b/tests/frontend/logging.py index a86bda577..f2be66e99 100644 --- a/tests/frontend/logging.py +++ b/tests/frontend/logging.py @@ -13,10 +13,10 @@ from buildstream.exceptions import ErrorDomain from buildstream.testing import cli # pylint: disable=unused-import # Project directory -DATA_DIR = os.path.join(os.path.dirname(os.path.realpath(__file__)), "project",) +DATA_DIR = os.path.dirname(os.path.realpath(__file__)) -@pytest.mark.datafiles(DATA_DIR) +@pytest.mark.datafiles(os.path.join(DATA_DIR, "project")) def test_default_logging(cli, tmpdir, datafiles): project = str(datafiles) bin_files_path = os.path.join(project, "files", "bin-files") @@ -41,7 +41,7 @@ def test_default_logging(cli, tmpdir, datafiles): assert m is not None -@pytest.mark.datafiles(DATA_DIR) +@pytest.mark.datafiles(os.path.join(DATA_DIR, "project")) def test_custom_logging(cli, tmpdir, datafiles): project = str(datafiles) bin_files_path = os.path.join(project, "files", "bin-files") @@ -73,7 +73,7 @@ def test_custom_logging(cli, tmpdir, datafiles): assert m is not None -@pytest.mark.datafiles(DATA_DIR) +@pytest.mark.datafiles(os.path.join(DATA_DIR, "project")) def test_failed_build_listing(cli, datafiles): project = str(datafiles) element_names = [] @@ -108,3 +108,106 @@ def test_failed_build_listing(cli, datafiles): # they have the name as expected. pattern = r"\[..:..:..\] FAILURE \[.*\] testfail-.\.bst: Staged artifacts do not provide command 'sh'" assert len(re.findall(pattern, result.stderr, re.MULTILINE)) == 6 # each element should be matched twice. + + +# This test ensures that we get the expected element name and cache key in log lines. +# +# * The master build log should show the element name and cache key +# of the task element, i.e. the element currently being built, not +# the element issuing the message. +# +# * In the individual task log, we expect to see the name and cache +# key of the element issuing messages, since the entire log file +# is contextual to the task, it makes more sense to provide the +# full context of the element issuing the log in this case. +# +# The order and format of log lines are UI and as such might change +# in which case this test needs to be adapted, the important part of +# this test is only that we see task elements reported in the aggregated +# master log file, and that we see message originating elements in +# a task specific log file. +# +@pytest.mark.datafiles(os.path.join(DATA_DIR, "logging")) +def test_log_line_element_names(cli, datafiles): + + project = str(datafiles) + + # First discover the cache keys, this will give us a dictionary + # where we can look up the brief cache key (as displayed in the logs) + # by the element name. + # + keys = {} + result = cli.run(project=project, args=["show", "--deps", "all", "--format", "%{name}||%{key}", "logtest.bst"]) + result.assert_success() + lines = result.output.splitlines() + for line in lines: + split = line.split(sep="||") + keys[split[0]] = split[1] + + # Run a build of the import elements, so that we can observe only the build of the logtest.bst element + # at the end. + # + result = cli.run(project=project, args=["build", "foo.bst", "bar.bst"]) + + # Now run the build + # + result = cli.run(project=project, args=["build", "logtest.bst"]) + result.assert_success() + master_log = result.stderr + + # Now run `bst artifact log` to conveniently collect the build log so we can compare it. + logfiles = os.path.join(project, "logfiles") + logfile = os.path.join(project, "logfiles", "logtest.log") + result = cli.run(project=project, args=["artifact", "log", "--out", logfiles, "logtest.bst"]) + result.assert_success() + + with open(logfile, "r") as f: + task_log = f.read() + + ######################################################### + # Parse and assert master log # + ######################################################### + + # In the master log, we're looking for lines like this: + # + # [--:--:--][10dc28c5][ build:logtest.bst ] STATUS Staging bar.bst/40ff1c5a + # [--:--:--][10dc28c5][ build:logtest.bst ] STATUS Staging foo.bst/e5ab75a1 + + # Capture (log key, element name, staged element name, staged element key) + pattern = r"\[--:--:--\]\[(\S*)\]\[\s*build:(\S*)\s*] STATUS Staging\s*(\S*)/(\S*)" + lines = re.findall(pattern, master_log, re.MULTILINE) + + # We staged 2 elements + assert len(lines) == 2 + + # Assert that the logtest.bst element name and it's cache key is used in the master log + for line in lines: + log_key, log_name, staged_name, staged_key = line + + assert log_name == "logtest.bst" + assert log_key == keys["logtest.bst"] + + ######################################################### + # Parse and assert artifact log # + ######################################################### + + # In the task specific build log, we're looking for lines like this: + # + # [--:--:--] STATUS [40ff1c5a] bar.bst: Staging bar.bst/40ff1c5a + # [--:--:--] STATUS [e5ab75a1] foo.bst: Staging foo.bst/e5ab75a1 + + # Capture (log key, element name, staged element name, staged element key) + pattern = r"\[--:--:--\] STATUS \[(\S*)\] (\S*): Staging\s*(\S*)/(\S*)" + lines = re.findall(pattern, task_log, re.MULTILINE) + + # We staged 2 elements + assert len(lines) == 2 + + # Assert that the originating element names and cache keys are used in + # log lines when recorded to the task specific log file + for line in lines: + log_key, log_name, staged_name, staged_key = line + + assert log_name == staged_name + assert log_key == staged_key + assert log_key == keys[log_name] diff --git a/tests/frontend/logging/elements/bar.bst b/tests/frontend/logging/elements/bar.bst new file mode 100644 index 000000000..db6f66526 --- /dev/null +++ b/tests/frontend/logging/elements/bar.bst @@ -0,0 +1,4 @@ +kind: import +sources: +- kind: local + path: files/bar diff --git a/tests/frontend/logging/elements/foo.bst b/tests/frontend/logging/elements/foo.bst new file mode 100644 index 000000000..487b8e2a5 --- /dev/null +++ b/tests/frontend/logging/elements/foo.bst @@ -0,0 +1,4 @@ +kind: import +sources: +- kind: local + path: files/foo diff --git a/tests/frontend/logging/elements/logtest.bst b/tests/frontend/logging/elements/logtest.bst new file mode 100644 index 000000000..cbfbaf86f --- /dev/null +++ b/tests/frontend/logging/elements/logtest.bst @@ -0,0 +1,5 @@ +kind: logtest + +depends: +- foo.bst +- bar.bst diff --git a/tests/frontend/logging/files/bar b/tests/frontend/logging/files/bar new file mode 100644 index 000000000..e69de29bb --- /dev/null +++ b/tests/frontend/logging/files/bar diff --git a/tests/frontend/logging/files/foo b/tests/frontend/logging/files/foo new file mode 100644 index 000000000..e69de29bb --- /dev/null +++ b/tests/frontend/logging/files/foo diff --git a/tests/frontend/logging/plugins/logtest.py b/tests/frontend/logging/plugins/logtest.py new file mode 100644 index 000000000..0817a92d8 --- /dev/null +++ b/tests/frontend/logging/plugins/logtest.py @@ -0,0 +1,44 @@ +from buildstream import Element + + +class LogTest(Element): + BST_MIN_VERSION = "2.0" + + def configure(self, node): + pass + + def preflight(self): + pass + + def get_unique_key(self): + return {} + + def configure_sandbox(self, sandbox): + pass + + def stage(self, sandbox): + # Here we stage the artifacts of dependencies individually without + # using a timed activity or suppressing the logging. + # + # This allows us to test the logging behavior when log lines are + # triggered by an element which is not the element being processed. + # + # * The master build log should show the element name and cache key + # of the task element, i.e. the element currently being built, not + # the element issuing the message. + # + # * In the individual task log, we expect to see the name and cache + # key of the element issuing messages, since the entire log file + # is contextual to the task, it makes more sense to provide the + # full context of the element issuing the log in this case. + # + for dep in self.dependencies(): + dep.stage_artifact(sandbox) + + def assemble(self, sandbox): + return "/" + + +# Plugin entry point +def setup(): + return LogTest diff --git a/tests/frontend/logging/project.conf b/tests/frontend/logging/project.conf new file mode 100644 index 000000000..151b0cd1a --- /dev/null +++ b/tests/frontend/logging/project.conf @@ -0,0 +1,10 @@ +# Project config for frontend build test +name: test +min-version: 2.0 +element-path: elements + +plugins: +- origin: local + path: plugins + elements: + - logtest |