From 51e3c98a7bb496fa8fe797d6f0d0fb5cc10fe0f3 Mon Sep 17 00:00:00 2001 From: Manoel Aranda Neto Date: Fri, 19 Jun 2026 12:34:55 +0200 Subject: [PATCH 1/2] fix: Prefix SDK log messages --- .changeset/polite-wolves-warn.md | 5 +++++ posthog/_logging.py | 27 ++++++++++++++++++++++++++ posthog/client.py | 3 +++ posthog/consumer.py | 4 ++++ posthog/request.py | 4 ++++ posthog/test/logging_helpers.py | 25 ++++++++++++++++++++++++ posthog/test/test_client.py | 24 +++++++++++++++++++++-- posthog/test/test_consumer.py | 13 +++++++++++++ posthog/test/test_exception_capture.py | 2 +- posthog/test/test_request.py | 23 ++++++++++++++++++++++ 10 files changed, 127 insertions(+), 3 deletions(-) create mode 100644 .changeset/polite-wolves-warn.md create mode 100644 posthog/_logging.py create mode 100644 posthog/test/logging_helpers.py diff --git a/.changeset/polite-wolves-warn.md b/.changeset/polite-wolves-warn.md new file mode 100644 index 00000000..fd6be0e1 --- /dev/null +++ b/.changeset/polite-wolves-warn.md @@ -0,0 +1,5 @@ +--- +'pypi/posthog': patch +--- + +Prefix PostHog SDK log messages so they remain identifiable with message-only logging formatters. diff --git a/posthog/_logging.py b/posthog/_logging.py new file mode 100644 index 00000000..3bc93198 --- /dev/null +++ b/posthog/_logging.py @@ -0,0 +1,27 @@ +import logging + + +_POSTHOG_LOG_PREFIX = "[PostHog]" +_POSTHOG_LOGGER_NAME = "posthog" + + +class _PostHogLogPrefixFilter(logging.Filter): + """Ensure PostHog SDK log messages are identifiable with message-only formatters.""" + + def filter(self, record: logging.LogRecord) -> bool: + if getattr(record, "_posthog_log_prefix_applied", False): + return True + + message = record.getMessage() + if not message.startswith(_POSTHOG_LOG_PREFIX): + record.msg = f"{_POSTHOG_LOG_PREFIX} {message}" + record.args = () + + record._posthog_log_prefix_applied = True + return True + + +def _configure_posthog_logging() -> None: + logger = logging.getLogger(_POSTHOG_LOGGER_NAME) + if not any(isinstance(f, _PostHogLogPrefixFilter) for f in logger.filters): + logger.addFilter(_PostHogLogPrefixFilter()) diff --git a/posthog/client.py b/posthog/client.py index 800cc577..bdb9adac 100644 --- a/posthog/client.py +++ b/posthog/client.py @@ -27,6 +27,7 @@ new_context, ) from posthog.exception_capture import ExceptionCapture +from posthog._logging import _configure_posthog_logging from posthog.exception_utils import ( DEFAULT_CODE_VARIABLES_IGNORE_PATTERNS, DEFAULT_CODE_VARIABLES_MASK_PATTERNS, @@ -97,6 +98,8 @@ from queue import Queue, Full +_configure_posthog_logging() + MAX_DICT_SIZE = 50_000 diff --git a/posthog/consumer.py b/posthog/consumer.py index 9f208662..567292e8 100644 --- a/posthog/consumer.py +++ b/posthog/consumer.py @@ -4,6 +4,7 @@ import time from threading import Thread +from posthog._logging import _configure_posthog_logging from posthog.request import ( AI_EVENTS_ENDPOINT, EVENTS_ENDPOINT, @@ -28,6 +29,9 @@ BATCH_SIZE_LIMIT = 5 * 1024 * 1024 +_configure_posthog_logging() + + class Consumer(Thread): """Consumes the messages from the client's queue.""" diff --git a/posthog/request.py b/posthog/request.py index 6d38ee0b..de16f33a 100644 --- a/posthog/request.py +++ b/posthog/request.py @@ -13,6 +13,7 @@ from urllib3.connection import HTTPConnection from urllib3.util.retry import Retry +from posthog._logging import _configure_posthog_logging from posthog.utils import remove_trailing_slash from posthog.version import VERSION @@ -196,6 +197,9 @@ def disable_connection_reuse() -> None: USER_AGENT = "posthog-python/" + VERSION +_configure_posthog_logging() + + def normalize_host(host: Optional[str]) -> str: """Normalize a configured host, defaulting blank values to DEFAULT_HOST.""" normalized_host = (host or "").strip() diff --git a/posthog/test/logging_helpers.py b/posthog/test/logging_helpers.py new file mode 100644 index 00000000..54fe52a8 --- /dev/null +++ b/posthog/test/logging_helpers.py @@ -0,0 +1,25 @@ +import io +import logging +from contextlib import contextmanager +from typing import Iterator + + +@contextmanager +def capture_message_only_logs(level: int = logging.DEBUG) -> Iterator[io.StringIO]: + logger = logging.getLogger("posthog") + stream = io.StringIO() + handler = logging.StreamHandler(stream) + handler.setFormatter(logging.Formatter("%(message)s")) + + previous_level = logger.level + previous_propagate = logger.propagate + logger.addHandler(handler) + logger.setLevel(level) + logger.propagate = False + try: + yield stream + finally: + logger.removeHandler(handler) + handler.close() + logger.setLevel(previous_level) + logger.propagate = previous_propagate diff --git a/posthog/test/test_client.py b/posthog/test/test_client.py index e9d7054c..62453ba2 100644 --- a/posthog/test/test_client.py +++ b/posthog/test/test_client.py @@ -1,3 +1,4 @@ +import logging import time import unittest from datetime import datetime @@ -9,6 +10,7 @@ from posthog.client import Client from posthog.contexts import get_context_session_id, new_context, set_context_session from posthog.request import APIError, GetResponse +from posthog.test.logging_helpers import capture_message_only_logs from posthog.test.test_utils import FAKE_TEST_API_KEY from posthog.types import FeatureFlag, LegacyFlagMetadata from posthog.version import VERSION @@ -80,6 +82,24 @@ def test_client_with_empty_api_key_is_noop(self): self.assertIsNone(client.capture("event", distinct_id="distinct_id")) + def test_message_only_info_logs_include_posthog_prefix(self): + self.client.flag_cache = mock.Mock() + self.client.flag_cache.get_stale_cached_flag.return_value = mock.Mock() + + with capture_message_only_logs(level=logging.INFO) as logs: + self.client._get_stale_flag_fallback("distinct_id", "flag-key") + + self.assertEqual( + logs.getvalue().strip(), + "[PostHog] [FEATURE FLAGS] Using stale cached value for flag flag-key", + ) + + def test_message_only_logs_do_not_duplicate_existing_posthog_prefix(self): + with capture_message_only_logs(level=logging.ERROR) as logs: + self.client.log.error("[PostHog] already prefixed") + + self.assertEqual(logs.getvalue().strip(), "[PostHog] already prefixed") + @mock.patch("posthog.client.get") def test_disabled_client_does_not_load_feature_flags(self, patch_get): client = Client("", personal_api_key="test", send=False) @@ -386,7 +406,7 @@ def test_basic_capture_exception_with_no_exception_happening(self): self.assertFalse(patch_capture.called) self.assertEqual( logs.output[0], - "WARNING:posthog:No exception information available", + "WARNING:posthog:[PostHog] No exception information available", ) def test_capture_exception_logs_when_enabled(self): @@ -396,7 +416,7 @@ def test_capture_exception_logs_when_enabled(self): Exception("test exception"), distinct_id="distinct_id" ) self.assertEqual( - logs.output[0], "ERROR:posthog:test exception\nNoneType: None" + logs.output[0], "ERROR:posthog:[PostHog] test exception\nNoneType: None" ) @mock.patch("posthog.client.flags") diff --git a/posthog/test/test_consumer.py b/posthog/test/test_consumer.py index f476b82a..c136e2b3 100644 --- a/posthog/test/test_consumer.py +++ b/posthog/test/test_consumer.py @@ -13,6 +13,7 @@ from posthog.consumer import MAX_MSG_SIZE, Consumer from posthog.request import APIError +from posthog.test.logging_helpers import capture_message_only_logs from posthog.test.test_utils import TEST_API_KEY @@ -54,6 +55,18 @@ def test_upload(self) -> None: success = consumer.upload() self.assertTrue(success) + def test_message_only_error_logs_include_posthog_prefix(self) -> None: + q = Queue() + consumer = Consumer(q, TEST_API_KEY) + q.put(_track_event()) + + with mock.patch.object(consumer, "request", side_effect=Exception("boom")): + with capture_message_only_logs() as logs: + success = consumer.upload() + + self.assertFalse(success) + self.assertEqual(logs.getvalue().strip(), "[PostHog] error uploading: boom") + def test_flush_interval(self) -> None: # Put _n_ items in the queue, pausing a little bit more than # _flush_interval_ after each one. diff --git a/posthog/test/test_exception_capture.py b/posthog/test/test_exception_capture.py index 702c7bbb..155a144c 100644 --- a/posthog/test/test_exception_capture.py +++ b/posthog/test/test_exception_capture.py @@ -149,7 +149,7 @@ def test_excepthook(tmpdir): assert b"ZeroDivisionError" in output assert b"LOL" in output - assert b"DEBUG:posthog:data uploaded successfully" in output + assert b"DEBUG:posthog:[PostHog] data uploaded successfully" in output assert ( b'"$exception_list": [{"mechanism": {"type": "generic", "handled": true}, "module": null, "type": "ZeroDivisionError", "value": "division by zero", "stacktrace": {"frames": [{"platform": "python", "filename": "app.py", "abs_path"' in output diff --git a/posthog/test/test_request.py b/posthog/test/test_request.py index d14e2dd7..4cae68f9 100644 --- a/posthog/test/test_request.py +++ b/posthog/test/test_request.py @@ -7,6 +7,7 @@ import requests import posthog.request as request_module +from posthog.test.logging_helpers import capture_message_only_logs from posthog.request import ( APIError, DatetimeSerializer, @@ -84,6 +85,28 @@ def test_post_sends_snake_case_sent_at(key, expected_present): assert (key in data) is expected_present +def test_message_only_debug_logs_include_posthog_prefix(): + mock_response = requests.Response() + mock_response.status_code = 200 + mock_session = mock.MagicMock() + mock_session.post.return_value = mock_response + + with capture_message_only_logs() as logs: + request_module.post( + TEST_API_KEY, + host="https://test.posthog.com", + path="/batch/", + session=mock_session, + batch=[], + ) + + assert logs.getvalue().splitlines() == [ + mock.ANY, + "[PostHog] data uploaded successfully", + ] + assert logs.getvalue().splitlines()[0].startswith("[PostHog] making request: ") + + class TestRequests(unittest.TestCase): def test_valid_request(self): res = batch_post( From 36cabc560256d110eb300a0700114178af8bfc53 Mon Sep 17 00:00:00 2001 From: Manoel Aranda Neto Date: Fri, 19 Jun 2026 14:14:41 +0200 Subject: [PATCH 2/2] test: use shared PostHog logger name --- posthog/test/logging_helpers.py | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/posthog/test/logging_helpers.py b/posthog/test/logging_helpers.py index 54fe52a8..ae1ca6fd 100644 --- a/posthog/test/logging_helpers.py +++ b/posthog/test/logging_helpers.py @@ -3,10 +3,12 @@ from contextlib import contextmanager from typing import Iterator +from posthog._logging import _POSTHOG_LOGGER_NAME + @contextmanager def capture_message_only_logs(level: int = logging.DEBUG) -> Iterator[io.StringIO]: - logger = logging.getLogger("posthog") + logger = logging.getLogger(_POSTHOG_LOGGER_NAME) stream = io.StringIO() handler = logging.StreamHandler(stream) handler.setFormatter(logging.Formatter("%(message)s"))