feat(logging): Bug 2039779 Copy chain_of_trust.log to live_backing.log on CoT verification failure

src/scriptworker/artifacts.py

@@ -183,6 +183,29 @@ async def create_artifact(context, path, target_path, content_type, content_enco
                     raise ScriptWorkerRetryException("Bad status {}".format(resp.status))
 
 
+async def create_link_artifact(context, target_path, link_to, content_type, expires=None):
+    """Create a Taskcluster link artifact that redirects to another artifact in the same task.
+
+    Args:
+        context (scriptworker.context.Context): the scriptworker context.
+        target_path (str): the artifact name to create (e.g., ``public/logs/live_backing.log``).
+        link_to (str): the artifact name to link to (e.g., ``public/logs/chain_of_trust.log``).
+        content_type (str): Content type (MIME type) of the linked artifact.
+        expires (str, optional): ISO datestring of when the artifact expires.
+            Defaults to ``context.task["expires"]``.
+
+    """
+    payload = {
+        "storageType": "link",
+        "expires": expires or get_expiration_arrow(context).isoformat(),
+        "contentType": content_type,
+        "artifact": link_to,
+    }
+    args = [get_task_id(context.claim_task), get_run_id(context.claim_task), target_path, payload]
+    log.info("Creating link artifact {} -> {}".format(target_path, link_to))
+    await context.temp_queue.createArtifact(*args)
+
+
 def _craft_artifact_put_headers(content_type, encoding=None):
     log.debug("{} {}".format(content_type, encoding))
     headers = {aiohttp.hdrs.CONTENT_TYPE: content_type}

src/scriptworker/cot/verify.py

@@ -41,7 +41,7 @@
 from scriptworker.ed25519 import ed25519_public_key_from_string, verify_ed25519_signature
 from scriptworker.exceptions import BaseDownloadError, CoTError, ScriptWorkerEd25519Error
 from scriptworker.github import GitHubRepository, extract_github_repo_full_name, extract_github_repo_owner_and_name, extract_github_repo_ssh_url
-from scriptworker.log import contextual_log_handler
+from scriptworker.log import contextual_log_handler, get_chain_of_trust_log_filename
 from scriptworker.task import (
     get_action_callback_name,
     get_and_check_tasks_for,
@@ -729,10 +729,7 @@ async def download_cot_artifact(chain, task_id, path):
     link = chain.get_link(task_id)
     log.debug("Verifying {} is in {} cot artifacts...".format(path, task_id))
     if not link.cot:
-        log.warning(
-            'Chain of Trust for "{}" in {} does not exist. See above log for more details. \
-Skipping download of this artifact'.format(path, task_id)
-        )
+        log.warning(f'Chain of Trust for "{path}" in {task_id} does not exist. See above log for more details. Skipping download of this artifact.')
         return
 
     if path not in link.cot["artifacts"]:
@@ -2045,7 +2042,7 @@ async def verify_chain_of_trust(chain, *, check_task=False):
         CoTError: on failure
 
     """
-    log_path = os.path.join(chain.context.config["task_log_dir"], "chain_of_trust.log")
+    log_path = get_chain_of_trust_log_filename(chain.context)
     scriptworker_log = logging.getLogger("scriptworker")
     with contextual_log_handler(
         chain.context,

src/scriptworker/log.py

@@ -115,6 +115,19 @@ def get_log_filename(context: Any) -> str:
     return os.path.join(context.config["task_log_dir"], "live_backing.log")
 
 
+def get_chain_of_trust_log_filename(context: Any) -> str:
+    """Get the chain of trust verification log file path.
+
+    Args:
+        context (scriptworker.context.Context): the scriptworker context.
+
+    Returns:
+        string: chain of trust log file path
+
+    """
+    return os.path.join(context.config["task_log_dir"], "chain_of_trust.log")
+
+
 @contextmanager
 def get_log_filehandle(context: Any) -> Iterator[IO[str]]:
     """Open the log and error filehandles.

src/scriptworker/worker.py

@@ -8,6 +8,7 @@
 
 import asyncio
 import logging
+import os
 import signal
 import socket
 import sys
@@ -17,12 +18,13 @@
 import aiohttp
 import arrow
 
-from scriptworker.artifacts import upload_artifacts
+from scriptworker.artifacts import create_link_artifact, upload_artifacts
 from scriptworker.config import get_context_from_cmdln
 from scriptworker.constants import STATUSES
 from scriptworker.cot.generate import generate_cot
 from scriptworker.cot.verify import ChainOfTrust, verify_chain_of_trust
 from scriptworker.exceptions import ScriptWorkerException, WorkerShutdownDuringTask
+from scriptworker.log import get_chain_of_trust_log_filename
 from scriptworker.task import claim_work, complete_task, prepare_to_run_task, reclaim_task, run_task, worst_level
 from scriptworker.task_process import TaskProcess
 from scriptworker.utils import cleanup, filepaths_in_dir, scriptworker_session
@@ -53,7 +55,21 @@ async def do_run_task(context, run_cancellable, to_cancellable_process):
     try:
         if context.config["verify_chain_of_trust"]:
             chain = ChainOfTrust(context, context.config["cot_job_type"])
-            await run_cancellable(verify_chain_of_trust(chain))
+            try:
+                await run_cancellable(verify_chain_of_trust(chain))
+            except Exception:
+                # Point live_backing.log at chain_of_trust.log so Treeherder parses the CoT failure
+                if os.path.exists(get_chain_of_trust_log_filename(context)):
+                    try:
+                        await create_link_artifact(
+                            context,
+                            target_path="public/logs/live_backing.log",
+                            link_to="public/logs/chain_of_trust.log",
+                            content_type="text/plain",
+                        )
+                    except Exception as link_exc:
+                        log.warning("Failed to create live_backing.log link artifact: {}".format(link_exc))
+                raise
         status = await run_task(context, to_cancellable_process)
         generate_cot(context)
     except asyncio.CancelledError:

tests/test_artifacts.py

@@ -14,6 +14,7 @@
     _craft_artifact_put_headers,
     compress_artifact_if_supported,
     create_artifact,
+    create_link_artifact,
     download_artifacts,
     get_and_check_single_upstream_artifact_full_path,
     get_artifact_url,
@@ -161,6 +162,34 @@ async def test_create_artifact_retry(context, fake_session_500, successful_queue
         await create_artifact(context, path, "public/env/one.log", content_type="text/plain", content_encoding=None, expires=expires)
 
 
+@pytest.mark.asyncio
+async def test_create_link_artifact(context, successful_queue):
+    expires = arrow.utcnow().isoformat()
+    context.temp_queue = successful_queue
+    await create_link_artifact(
+        context,
+        target_path="public/logs/live_backing.log",
+        link_to="public/logs/chain_of_trust.log",
+        content_type="text/plain",
+        expires=expires,
+    )
+    assert successful_queue.info == [
+        "createArtifact",
+        (
+            "taskId",
+            0,
+            "public/logs/live_backing.log",
+            {
+                "storageType": "link",
+                "expires": expires,
+                "contentType": "text/plain",
+                "artifact": "public/logs/chain_of_trust.log",
+            },
+        ),
+        {},
+    ]
+
+
 def test_craft_artifact_put_headers():
     assert _craft_artifact_put_headers("text/plain") == {"Content-Type": "text/plain"}
     assert _craft_artifact_put_headers("text/plain", encoding=None) == {"Content-Type": "text/plain"}

tests/test_log.py

@@ -40,6 +40,11 @@ def test_get_log_filename(rw_context):
     assert log_file == os.path.join(rw_context.config["task_log_dir"], "live_backing.log")
 
 
+def test_get_chain_of_trust_log_filename(rw_context):
+    log_file = swlog.get_chain_of_trust_log_filename(rw_context)
+    assert log_file == os.path.join(rw_context.config["task_log_dir"], "chain_of_trust.log")
+
+
 def test_get_log_filehandle(rw_context, text):
     log_file = swlog.get_log_filename(rw_context)
     with swlog.get_log_filehandle(rw_context) as log_fh:

tests/test_worker.py

@@ -254,6 +254,90 @@ async def run(coroutine):
     assert status == STATUSES["internal-error"]
 
 
+@pytest.mark.asyncio
+async def test_verify_chain_of_trust_failure_creates_link_artifact(context, mocker):
+    """When verify_chain_of_trust fails, a link artifact is created pointing live_backing.log -> chain_of_trust.log."""
+    context.config["verify_chain_of_trust"] = True
+    cot_log = os.path.join(context.config["task_log_dir"], "chain_of_trust.log")
+    os.makedirs(context.config["task_log_dir"], exist_ok=True)
+    with open(cot_log, "w") as f:
+        f.write("CoT verification error details")
+
+    link_calls = []
+
+    async def fake_create_link(context, target_path, link_to, content_type, expires=None):
+        link_calls.append({"target_path": target_path, "link_to": link_to, "content_type": content_type})
+
+    def fail():
+        raise ScriptWorkerException("CoT failure")
+
+    async def run(coroutine):
+        await coroutine
+
+    mocker.patch.object(worker, "create_link_artifact", new=fake_create_link)
+    mocker.patch.object(worker, "ChainOfTrust", new=lambda *args, **kwargs: None)
+    mocker.patch.object(worker, "verify_chain_of_trust", new=fail)
+    status = await do_run_task(context, run, lambda x: x)
+    assert status == ScriptWorkerException.exit_code
+    assert link_calls == [
+        {
+            "target_path": "public/logs/live_backing.log",
+            "link_to": "public/logs/chain_of_trust.log",
+            "content_type": "text/plain",
+        }
+    ]
+
+
+@pytest.mark.asyncio
+async def test_verify_chain_of_trust_failure_no_cot_log(context, mocker):
+    """If chain_of_trust.log doesn't exist when verify fails, no link artifact is created and do_run_task doesn't crash."""
+    context.config["verify_chain_of_trust"] = True
+    os.makedirs(context.config["task_log_dir"], exist_ok=True)
+
+    link_calls = []
+
+    async def fake_create_link(*args, **kwargs):
+        link_calls.append(kwargs)
+
+    def fail():
+        raise ScriptWorkerException("CoT failure")
+
+    async def run(coroutine):
+        await coroutine
+
+    mocker.patch.object(worker, "create_link_artifact", new=fake_create_link)
+    mocker.patch.object(worker, "ChainOfTrust", new=lambda *args, **kwargs: None)
+    mocker.patch.object(worker, "verify_chain_of_trust", new=fail)
+    status = await do_run_task(context, run, lambda x: x)
+    assert status == ScriptWorkerException.exit_code
+    assert link_calls == []
+
+
+@pytest.mark.asyncio
+async def test_verify_chain_of_trust_failure_link_error_does_not_mask(context, mocker):
+    """If create_link_artifact itself fails, the original CoT exception is still raised and the task is still marked failed."""
+    context.config["verify_chain_of_trust"] = True
+    cot_log = os.path.join(context.config["task_log_dir"], "chain_of_trust.log")
+    os.makedirs(context.config["task_log_dir"], exist_ok=True)
+    with open(cot_log, "w") as f:
+        f.write("CoT verification error details")
+
+    async def fake_create_link(*args, **kwargs):
+        raise RuntimeError("createArtifact failed")
+
+    def fail():
+        raise ScriptWorkerException("CoT failure")
+
+    async def run(coroutine):
+        await coroutine
+
+    mocker.patch.object(worker, "create_link_artifact", new=fake_create_link)
+    mocker.patch.object(worker, "ChainOfTrust", new=lambda *args, **kwargs: None)
+    mocker.patch.object(worker, "verify_chain_of_trust", new=fail)
+    status = await do_run_task(context, run, lambda x: x)
+    assert status == ScriptWorkerException.exit_code
+
+
 @pytest.mark.asyncio
 async def test_run_tasks_timeout(context, successful_queue, mocker):
     expected_args = [(context, ["one", "public/two", "public/logs/live_backing.log"]), None]