[release] 1.0.1rc1: more logs and defensive mechanism for test collection

.editorconfig

@@ -0,0 +1,21 @@
+# EditorConfig is awesome: https://EditorConfig.org
+
+# top-most EditorConfig file
+root = true
+
+# Unix-style newlines with a newline ending every file
+[*]
+end_of_line = lf
+insert_final_newline = true
+charset = utf-8
+trim_trailing_whitespace = true
+
+# Python files
+[*.py]
+indent_style = space
+indent_size = 4
+
+# YAML files
+[*.{yml,yaml}]
+indent_style = space
+indent_size = 2

.gitignore

@@ -14,3 +14,5 @@ __pycache__
 .env*
 
 .direnv/*
+
+build

src/buildkite_test_collector/collector/api.py

@@ -2,22 +2,21 @@
 
 from typing import Optional
 from os import environ
-from sys import stderr
 import traceback
 from requests import post, Response
 from requests.exceptions import InvalidHeader, HTTPError
 from .payload import Payload
+from ..pytest_plugin.logger import logger
 
 
 def submit(payload: Payload, batch_size=100) -> Optional[Response]:
     """Submit a payload to the API"""
     token = environ.get("BUILDKITE_ANALYTICS_TOKEN")
-    debug = environ.get("BUILDKITE_ANALYTICS_DEBUG_ENABLED")
     api_url = environ.get("BUILDKITE_ANALYTICS_API_URL", "https://analytics-api.buildkite.com/v1")
     response = None
 
-    if debug and not token:
-        print("Warning: No `BUILDKITE_ANALYTICS_TOKEN` environment variable present", file=stderr)
+    if not token:
+        logger.warning("No `BUILDKITE_ANALYTICS_TOKEN` environment variable present")
 
     if token:
         try:
@@ -32,12 +31,12 @@ def submit(payload: Payload, batch_size=100) -> Optional[Response]:
                 response.raise_for_status()
                 return response
         except InvalidHeader as error:
-            print("Warning: Invalid `BUILDKITE_ANALYTICS_TOKEN` environment variable", file=stderr)
-            print(error, file=stderr)
+            logger.warning("Invalid `BUILDKITE_ANALYTICS_TOKEN` environment variable")
+            logger.warning(error)
         except HTTPError as err:
-            print("Warning: Failed to uploads test results to buildkite", file=stderr)
-            print(err, file=stderr)
-        except Exception: # pylint: disable=broad-except
+            logger.warning("Failed to uploads test results to buildkite")
+            logger.warning(err)
+        except Exception:  # pylint: disable=broad-except
             error_message = traceback.format_exc()
-            print(error_message, file=stderr)
+            logger.warning(error_message)
     return None

src/buildkite_test_collector/collector/constants.py

@@ -3,4 +3,4 @@
 """This module defines collector-level constants."""
 
 COLLECTOR_NAME='buildkite-test-collector'
-VERSION='1.0.0'
+VERSION='1.0.1rc1'

src/buildkite_test_collector/pytest_plugin/__init__.py

@@ -1,9 +1,6 @@
 # pylint: disable=line-too-long
 """Buildkite test collector for Pytest."""
 
-from logging import warning
-from os import environ
-
 import pytest
 
 from ..collector.payload import Payload

src/buildkite_test_collector/pytest_plugin/buildkite_plugin.py

@@ -3,6 +3,7 @@
 from uuid import uuid4
 
 from ..collector.payload import TestData
+from .logger import logger
 
 class BuildkitePlugin:
     """Buildkite test collector plugin for Pytest"""
@@ -14,6 +15,7 @@ def __init__(self, payload):
 
     def pytest_runtest_logstart(self, nodeid, location):
         """pytest_runtest_logstart hook callback"""
+        logger.debug('Enter pytest_runtest_logstart for %s', nodeid)
         if not self.payload.is_started():
             self.payload = self.payload.started()
 
@@ -41,6 +43,7 @@ def pytest_runtest_logreport(self, report):
 
         nodeid = report.nodeid
         test_data = self.in_flight.get(nodeid)
+        logger.debug('Enter pytest_runtest_logreport for %s', nodeid)
 
         if test_data:
             if report.passed:
@@ -59,6 +62,7 @@ def pytest_runtest_logreport(self, report):
 
     def pytest_runtest_teardown(self, item):
         """pytest_runtest_hook hook callback to mark test as finished and add it to the payload"""
+        logger.debug('Enter pytest_runtest_teardown for %s', item.nodeid)
         test_data = self.in_flight.get(item.nodeid)
 
         if test_data:
@@ -68,8 +72,34 @@ def pytest_runtest_teardown(self, item):
             for tag in tags:
                 test_data = test_data.tag_execution(tag.args[0], tag.args[1])
 
-            del self.in_flight[item.nodeid]
+            self.in_flight[item.nodeid] = test_data
+
+            self.finalize_test(item.nodeid)
+        else:
+            logger.warning('Unexpected missing test_data during pytest_runtest_teardown')
+
+    # Strictly speaking, we do not need this hook.
+    # But in pytest it's hard to predict how plugins interfere each other.
+    # So let's be defensive here.
+    def pytest_runtest_logfinish(self, nodeid, location):  # pylint: disable=unused-argument
+        """pytest_runtest_logfinish hook always runs in the very end"""
+        logger.debug('Enter pytest_runtest_logfinish for %s', nodeid)
+        if self.finalize_test(nodeid):
+            logger.warning(
+                'Detected possible interference in pytest_runtest_teardown hook. '
+                'Falling back to pytest_runtest_logfinish, but note that test tags '
+                'will not be uploaded.'
+            )
+
+
+    def finalize_test(self, nodeid):
+        """ Attempting to move test data for a nodeid to payload area for upload """
+        test_data = self.in_flight.get(nodeid)
+        if test_data:
+            del self.in_flight[nodeid]
             self.payload = self.payload.push_test_data(test_data)
+            return True
+        return False
 
     def save_payload_as_json(self, path):
         """ Save payload into a json file """

src/buildkite_test_collector/pytest_plugin/logger.py

@@ -0,0 +1,38 @@
+"""A plugin internal logger, use DEBUG=1 env var to turn on all debug logs"""
+import os
+import logging
+
+def setup_logger(name=__name__):
+    """
+    Configure and return a logger with the specified name.
+
+    The logger's level is set based on the DEBUG environment variable.
+    If DEBUG=1, the level is set to DEBUG, otherwise it's set to INFO.
+
+    Args:
+        name (str): The name for the logger. Defaults to the current module name.
+
+    Returns:
+        logging.Logger: A configured logger instance.
+    """
+    l = logging.getLogger(name)
+
+    # Set level based on DEBUG env var
+    l.setLevel(logging.DEBUG if os.getenv("DEBUG") == "1" else logging.INFO)
+
+    # Add handler only if none exists (prevents duplicate logs)
+    if not l.handlers:
+        handler = logging.StreamHandler()  # Log to console
+        formatter = logging.Formatter(
+            "%(name)s - %(levelname)s - %(message)s"
+        )
+        handler.setFormatter(formatter)
+        l.addHandler(handler)
+
+    # Optional: Stop propagation to root logger
+    l.propagate = False
+
+    return l
+
+# Example default logger (optional)
+logger = setup_logger("buildkite-test-collector")

tests/buildkite_test_collector/collector/test_api.py

@@ -42,7 +42,7 @@ def test_submit_with_payload_timeout_captures_ConnectTimeout_error(capfd, succes
         result = submit(payload)
         captured = capfd.readouterr()
 
-        assert captured.err.startswith("Traceback")
+        assert captured.err.startswith("buildkite-test-collector - WARNING -")
         assert "ConnectTimeout" in captured.err
 
 @responses.activate
@@ -62,7 +62,7 @@ def test_submit_with_payload_timeout_captures_ReadTimeout_error(capfd, successfu
         result = submit(payload)
         captured = capfd.readouterr()
 
-        assert captured.err.startswith("Traceback")
+        assert captured.err.startswith("buildkite-test-collector - WARNING -")
         assert "ReadTimeout" in captured.err
 
 @responses.activate