Fix failure-report timestamp skew on non-UTC hosts in ES/OpenSearch/Splunk outputs (#812)

* Fix failure-report timestamp skew on non-UTC hosts in ES/OS/Splunk sinks

arrival_date_utc is a UTC wall-clock string (generated in
parse_failure_report via an aware-UTC strftime), but elastic.py,
opensearch.py, and splunk.py parsed it back into a naive datetime and
called .timestamp(), which per the Python docs interprets naive values
as local time (https://docs.python.org/3/library/datetime.html#datetime.datetime.timestamp).
On any non-UTC host the epoch stored as the ES/OpenSearch arrival_date
field, used in the failure-report dedup match query, and sent as the
Splunk HEC event time was therefore off by the host's UTC offset
(verified -3600 s under TZ=Europe/Warsaw in January).

Add an assume_utc keyword to human_timestamp_to_datetime() /
human_timestamp_to_unix_timestamp() that attaches timezone.utc to naive
parses, and use it at the three arrival_date_utc call sites. Aware
inputs (explicit offsets) are unaffected; all other callers keep the
existing local-time semantics, whose round-trip with timestamp_to_human
is self-consistent on a single host (the broader local-time output
question is tracked separately in issue #811 bug 2).

The three new sink regression tests fail on the unfixed code
(verified by stashing the source changes) and force TZ=Europe/Warsaw
via time.tzset() so they catch the skew even on UTC CI runners.

Fixes half of https://github.com/domainaware/parsedmarc/issues/811.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>

* Deduplicate TZ-forcing test boilerplate; fix unix-timestamp docstring

Extract the repeated TZ=Europe/Warsaw + time.tzset() setup/cleanup from
the four timestamp regression tests into a shared tests/tzutil.py
force_tz() helper, and correct human_timestamp_to_unix_timestamp()'s
docstring, which said the return type was float while the function
returns int.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>

---------

Co-authored-by: MISAPOR LAB <misapor@lab.misapor.pl>
Co-authored-by: Claude Fable 5 <noreply@anthropic.com>
Co-authored-by: Sean Whalen <44679+seanthegeek@users.noreply.github.com>
This commit is contained in:
Kili
2026-07-09 19:45:34 -04:00
committed by GitHub
co-authored by MISAPOR LAB Claude Fable 5 Sean Whalen
parent 15dd69cc28
commit cdda5dae62
10 changed files with 186 additions and 7 deletions
+6
View File
@@ -1,5 +1,11 @@
# Changelog # Changelog
## Unreleased
### Bug fixes
- **Failure-report timestamps are no longer skewed by the host's UTC offset in the Elasticsearch, OpenSearch, and Splunk HEC outputs** ([#811](https://github.com/domainaware/parsedmarc/issues/811), bug 1). `arrival_date_utc` is a UTC wall-clock string, but the three sinks parsed it into a naive `datetime` and called `.timestamp()`, which per the Python docs interprets naive values as *local* time — so on any non-UTC host, the epoch stored as the ES/OpenSearch `arrival_date` field, used in the failure-report dedup query, and sent as the Splunk HEC event `time` was off by the host's UTC offset (12 h for most of Europe). `human_timestamp_to_datetime()` / `human_timestamp_to_unix_timestamp()` gained an `assume_utc` keyword that attaches `timezone.utc` to naive parses, and the `arrival_date_utc` consumers now use it.
## 10.2.0 ## 10.2.0
### Changes ### Changes
+6 -1
View File
@@ -660,7 +660,12 @@ def save_failure_report_to_elasticsearch(
for original_header in original_headers: for original_header in original_headers:
headers[original_header.lower()] = original_headers[original_header] headers[original_header.lower()] = original_headers[original_header]
arrival_date = human_timestamp_to_datetime(failure_report["arrival_date_utc"]) # arrival_date_utc is a UTC wall-clock string; without assume_utc the
# naive .timestamp() below would interpret it as local time and skew
# the epoch by the host's UTC offset.
arrival_date = human_timestamp_to_datetime(
failure_report["arrival_date_utc"], assume_utc=True
)
arrival_date_epoch_milliseconds = int(arrival_date.timestamp() * 1000) arrival_date_epoch_milliseconds = int(arrival_date.timestamp() * 1000)
if index_suffix is not None: if index_suffix is not None:
+6 -1
View File
@@ -660,7 +660,12 @@ def save_failure_report_to_opensearch(
for original_header in original_headers: for original_header in original_headers:
headers[original_header.lower()] = original_headers[original_header] headers[original_header.lower()] = original_headers[original_header]
arrival_date = human_timestamp_to_datetime(failure_report["arrival_date_utc"]) # arrival_date_utc is a UTC wall-clock string; without assume_utc the
# naive .timestamp() below would interpret it as local time and skew
# the epoch by the host's UTC offset.
arrival_date = human_timestamp_to_datetime(
failure_report["arrival_date_utc"], assume_utc=True
)
arrival_date_epoch_milliseconds = int(arrival_date.timestamp() * 1000) arrival_date_epoch_milliseconds = int(arrival_date.timestamp() * 1000)
if index_suffix is not None: if index_suffix is not None:
+5 -1
View File
@@ -163,7 +163,11 @@ class HECClient(object):
for report in failure_reports: for report in failure_reports:
data = self._common_data.copy() data = self._common_data.copy()
data["sourcetype"] = "dmarc:failure" data["sourcetype"] = "dmarc:failure"
timestamp = human_timestamp_to_unix_timestamp(report["arrival_date_utc"]) # arrival_date_utc is a UTC wall-clock string; assume_utc keeps
# it from being re-interpreted as local time on non-UTC hosts.
timestamp = human_timestamp_to_unix_timestamp(
report["arrival_date_utc"], assume_utc=True
)
data["time"] = timestamp data["time"] = timestamp
data["event"] = report.copy() data["event"] = report.copy()
json_str += "{0}\n".format(json.dumps(data)) json_str += "{0}\n".format(json.dumps(data))
+17 -4
View File
@@ -359,7 +359,7 @@ def timestamp_to_human(timestamp: int) -> str:
def human_timestamp_to_datetime( def human_timestamp_to_datetime(
human_timestamp: str, *, to_utc: bool = False human_timestamp: str, *, to_utc: bool = False, assume_utc: bool = False
) -> datetime: ) -> datetime:
""" """
Converts a human-readable timestamp into a Python ``datetime`` object Converts a human-readable timestamp into a Python ``datetime`` object
@@ -367,6 +367,11 @@ def human_timestamp_to_datetime(
Args: Args:
human_timestamp (str): A timestamp string human_timestamp (str): A timestamp string
to_utc (bool): Convert the timestamp to UTC to_utc (bool): Convert the timestamp to UTC
assume_utc (bool): Treat a timestamp that carries no UTC offset as
UTC wall-clock time instead of local time. Pass this when the
string is known to be UTC (e.g. an ``arrival_date_utc`` value);
otherwise naive results are interpreted as local time by
``datetime.astimezone()`` / ``datetime.timestamp()``.
Returns: Returns:
datetime: The converted timestamp datetime: The converted timestamp
@@ -376,21 +381,29 @@ def human_timestamp_to_datetime(
human_timestamp = parenthesis_regex.sub("", human_timestamp) human_timestamp = parenthesis_regex.sub("", human_timestamp)
dt = parse_date(human_timestamp) dt = parse_date(human_timestamp)
if assume_utc and dt.tzinfo is None:
dt = dt.replace(tzinfo=timezone.utc)
return dt.astimezone(timezone.utc) if to_utc else dt return dt.astimezone(timezone.utc) if to_utc else dt
def human_timestamp_to_unix_timestamp(human_timestamp: str) -> int: def human_timestamp_to_unix_timestamp(
human_timestamp: str, *, assume_utc: bool = False
) -> int:
""" """
Converts a human-readable timestamp into a UNIX timestamp Converts a human-readable timestamp into a UNIX timestamp
Args: Args:
human_timestamp (str): A timestamp in `YYYY-MM-DD HH:MM:SS`` format human_timestamp (str): A timestamp in `YYYY-MM-DD HH:MM:SS`` format
assume_utc (bool): Treat a timestamp that carries no UTC offset as
UTC wall-clock time instead of local time
Returns: Returns:
float: The converted timestamp int: The converted timestamp
""" """
human_timestamp = human_timestamp.replace("T", " ") human_timestamp = human_timestamp.replace("T", " ")
return int(human_timestamp_to_datetime(human_timestamp).timestamp()) return int(
human_timestamp_to_datetime(human_timestamp, assume_utc=assume_utc).timestamp()
)
_IP_DB_PATH: str | None = None _IP_DB_PATH: str | None = None
+21
View File
@@ -6,6 +6,7 @@ transformation logic — document construction, index naming, deduplication
queries, error wrapping — without needing a running Elasticsearch cluster. queries, error wrapping — without needing a running Elasticsearch cluster.
""" """
import time
import unittest import unittest
from unittest.mock import MagicMock, call, patch from unittest.mock import MagicMock, call, patch
@@ -21,6 +22,7 @@ from parsedmarc.elastic import (
save_smtp_tls_report_to_elasticsearch, save_smtp_tls_report_to_elasticsearch,
set_hosts, set_hosts,
) )
from tests.tzutil import force_tz
# --------------------------------------------------------------------------- # ---------------------------------------------------------------------------
@@ -660,6 +662,25 @@ class TestSaveFailureReport(unittest.TestCase):
index_calls = [c.args[0] for c in mock_index_cls.call_args_list] index_calls = [c.args[0] for c in mock_index_cls.call_args_list]
self.assertIn("dmarc_failure-2024-01", index_calls) self.assertIn("dmarc_failure-2024-01", index_calls)
@unittest.skipUnless(hasattr(time, "tzset"), "requires POSIX time.tzset()")
def test_arrival_date_epoch_is_utc_regardless_of_host_timezone(self):
"""arrival_date_utc is a UTC wall-clock string; the epoch-ms
value stored in the document (and used in the dedup query) must
be its true UTC epoch on any host. Regression test for
https://github.com/domainaware/parsedmarc/issues/811 (bug 1):
the naive parse used to shift the stored epoch by the host's
UTC offset."""
force_tz(self)
with (
patch("parsedmarc.elastic.Search", return_value=_empty_search()),
patch("parsedmarc.elastic.Index"),
patch("parsedmarc.elastic._FailureReportDoc") as mock_doc_cls,
):
save_failure_report_to_elasticsearch(_failure_report())
# Fixture arrival_date_utc is 2024-01-01 00:00:00 UTC.
self.assertEqual(mock_doc_cls.call_args.kwargs["arrival_date"], 1704067200000)
def test_failure_search_index_with_suffix_and_prefix(self): def test_failure_search_index_with_suffix_and_prefix(self):
"""When both suffix and prefix are set, the dedup search """When both suffix and prefix are set, the dedup search
pattern joins them onto BOTH dmarc_failure* and pattern joins them onto BOTH dmarc_failure* and
+21
View File
@@ -6,6 +6,7 @@ transformation logic — document construction, index naming, deduplication
queries, error wrapping — without needing a running OpenSearch cluster. queries, error wrapping — without needing a running OpenSearch cluster.
""" """
import time
import unittest import unittest
from unittest.mock import MagicMock, call, patch from unittest.mock import MagicMock, call, patch
@@ -21,6 +22,7 @@ from parsedmarc.opensearch import (
save_smtp_tls_report_to_opensearch, save_smtp_tls_report_to_opensearch,
set_hosts, set_hosts,
) )
from tests.tzutil import force_tz
# --------------------------------------------------------------------------- # ---------------------------------------------------------------------------
@@ -658,6 +660,25 @@ class TestSaveFailureReport(unittest.TestCase):
index_calls = [c.args[0] for c in mock_index_cls.call_args_list] index_calls = [c.args[0] for c in mock_index_cls.call_args_list]
self.assertIn("dmarc_failure-2024-01", index_calls) self.assertIn("dmarc_failure-2024-01", index_calls)
@unittest.skipUnless(hasattr(time, "tzset"), "requires POSIX time.tzset()")
def test_arrival_date_epoch_is_utc_regardless_of_host_timezone(self):
"""arrival_date_utc is a UTC wall-clock string; the epoch-ms
value stored in the document (and used in the dedup query) must
be its true UTC epoch on any host. Regression test for
https://github.com/domainaware/parsedmarc/issues/811 (bug 1):
the naive parse used to shift the stored epoch by the host's
UTC offset."""
force_tz(self)
with (
patch("parsedmarc.opensearch.Search", return_value=_empty_search()),
patch("parsedmarc.opensearch.Index"),
patch("parsedmarc.opensearch._FailureReportDoc") as mock_doc_cls,
):
save_failure_report_to_opensearch(_failure_report())
# Fixture arrival_date_utc is 2024-01-01 00:00:00 UTC.
self.assertEqual(mock_doc_cls.call_args.kwargs["arrival_date"], 1704067200000)
def test_failure_search_index_with_suffix_and_prefix(self): def test_failure_search_index_with_suffix_and_prefix(self):
"""When both suffix and prefix are set, the dedup search """When both suffix and prefix are set, the dedup search
pattern joins them onto BOTH dmarc_failure* and pattern joins them onto BOTH dmarc_failure* and
+20
View File
@@ -1,10 +1,12 @@
"""Tests for parsedmarc.splunk""" """Tests for parsedmarc.splunk"""
import json import json
import time
import unittest import unittest
from unittest.mock import MagicMock from unittest.mock import MagicMock
from parsedmarc.splunk import HECClient, SplunkError from parsedmarc.splunk import HECClient, SplunkError
from tests.tzutil import force_tz
def _aggregate_report(): def _aggregate_report():
@@ -323,6 +325,24 @@ class TestSaveFailureReportsToSplunk(unittest.TestCase):
client.save_failure_reports_to_splunk([]) client.save_failure_reports_to_splunk([])
client.session.post.assert_not_called() client.session.post.assert_not_called()
@unittest.skipUnless(hasattr(time, "tzset"), "requires POSIX time.tzset()")
def test_event_time_treats_arrival_date_utc_as_utc(self):
"""arrival_date_utc is a UTC wall-clock string; the HEC event
`time` must be its true UTC epoch regardless of the host
timezone. Regression test for
https://github.com/domainaware/parsedmarc/issues/811 (bug 1):
the naive parse used to shift the epoch by the host's UTC
offset (-3600 s under Europe/Warsaw in January)."""
force_tz(self)
client = _client()
client.session = MagicMock()
client.session.post.return_value = _ok_response()
client.save_failure_reports_to_splunk(_failure_report())
event = json.loads(client.session.post.call_args.kwargs["data"].strip())
# Fixture arrival_date_utc is 2024-01-01 00:00:00 UTC.
self.assertEqual(event["time"], 1704067200)
def test_non_zero_response_code_raises_splunk_error(self): def test_non_zero_response_code_raises_splunk_error(self):
client = _client() client = _client()
client.session = MagicMock() client.session = MagicMock()
+54
View File
@@ -2,6 +2,7 @@
import os import os
import tempfile import tempfile
import time
import unittest import unittest
from datetime import datetime, timezone from datetime import datetime, timezone
from tempfile import NamedTemporaryFile from tempfile import NamedTemporaryFile
@@ -13,6 +14,7 @@ from expiringdict import ExpiringDict
import parsedmarc import parsedmarc
import parsedmarc.utils import parsedmarc.utils
from tests.tzutil import force_tz
class Test(unittest.TestCase): class Test(unittest.TestCase):
@@ -550,6 +552,58 @@ class TestUtilsDnsCaching(unittest.TestCase):
self.assertIsNone(result) self.assertIsNone(result)
@unittest.skipUnless(hasattr(time, "tzset"), "requires POSIX time.tzset()")
class TestTimestampAssumeUtc(unittest.TestCase):
"""Timestamp helpers must not re-interpret known-UTC strings as local
time. Per the Python docs, naive ``datetime.timestamp()`` and
``datetime.astimezone()`` assume the naive value is *local* time
(https://docs.python.org/3/library/datetime.html#datetime.datetime.timestamp),
so a UTC wall-clock string like ``arrival_date_utc`` parsed naive comes
out skewed by the host's UTC offset. ``assume_utc=True`` attaches
``timezone.utc`` instead. Regression tests for
https://github.com/domainaware/parsedmarc/issues/811 (bug 1)."""
# 2024-01-15 12:00:00 UTC
UTC_STRING = "2024-01-15 12:00:00"
TRUE_EPOCH = 1705320000
def setUp(self):
# Fixed non-UTC zone (UTC+1 in January) so the local-time
# misinterpretation this guards against would shift the epoch.
force_tz(self)
def testAssumeUtcYieldsAwareUtcDatetime(self):
dt = parsedmarc.utils.human_timestamp_to_datetime(
self.UTC_STRING, assume_utc=True
)
self.assertEqual(dt.tzinfo, timezone.utc)
self.assertEqual(int(dt.timestamp()), self.TRUE_EPOCH)
def testWithoutAssumeUtcNaiveIsLocal(self):
"""Documents the default: a naive parse followed by .timestamp()
uses local time — off by one hour under Europe/Warsaw in January.
This is the behavior arrival_date_utc consumers must avoid."""
dt = parsedmarc.utils.human_timestamp_to_datetime(self.UTC_STRING)
self.assertIsNone(dt.tzinfo)
self.assertEqual(int(dt.timestamp()), self.TRUE_EPOCH - 3600)
def testUnixTimestampHelperAssumeUtc(self):
self.assertEqual(
parsedmarc.utils.human_timestamp_to_unix_timestamp(
self.UTC_STRING, assume_utc=True
),
self.TRUE_EPOCH,
)
def testAssumeUtcDoesNotOverrideExplicitOffset(self):
"""A timestamp that carries its own offset keeps it; assume_utc
only applies to naive parses."""
dt = parsedmarc.utils.human_timestamp_to_datetime(
"2024-01-15 13:00:00 +0100", assume_utc=True
)
self.assertEqual(int(dt.timestamp()), self.TRUE_EPOCH)
class TestUtilsIpDbPaths(unittest.TestCase): class TestUtilsIpDbPaths(unittest.TestCase):
"""Tests for IP database path validation""" """Tests for IP database path validation"""
+30
View File
@@ -0,0 +1,30 @@
"""Shared timezone-forcing helper for timestamp regression tests."""
import os
import time
import unittest
def force_tz(testcase: unittest.TestCase, tz: str = "Europe/Warsaw") -> None:
"""Set the process timezone to *tz* for the duration of *testcase*.
Registers a cleanup that restores the previous ``TZ`` value.
Requires POSIX ``time.tzset()``; guard callers with
``@unittest.skipUnless(hasattr(time, "tzset"), ...)``.
The default zone is fixed and non-UTC (UTC+1 in January, UTC+2 in
summer), so code that wrongly interprets a UTC wall-clock string as
local time produces a shifted epoch under it.
"""
old_tz = os.environ.get("TZ")
os.environ["TZ"] = tz
time.tzset()
def restore() -> None:
if old_tz is None:
os.environ.pop("TZ", None)
else:
os.environ["TZ"] = old_tz
time.tzset()
testcase.addCleanup(restore)