Skip to content

Commit 8dc09ce

Browse files
authored
[DBMON-6495] Fix Mongo datatime conversion overflow (#23472)
* Fix datatime conversion overflow * Add changelog * Fix license header
1 parent 2d5e4ef commit 8dc09ce

3 files changed

Lines changed: 126 additions & 1 deletion

File tree

mongo/changelog.d/23472.fixed

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
1+
Fixed a datetime overflow when collecting slow operations from MongoDB 8.0 replica set logs containing out-of-range `$date` sentinel values in RSM topology change entries.

mongo/datadog_checks/mongo/dbm/slow_operations.py

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@
88
from datetime import datetime, timezone
99

1010
from bson import json_util
11+
from bson.codec_options import DatetimeConversion
1112
from cachetools import TTLCache
1213
from pymongo.errors import OperationFailure
1314

@@ -68,7 +69,10 @@ def __init__(self, check):
6869

6970
self._last_collection_timestamp = None
7071

71-
self._log_json_opts = json_util.JSONOptions(tz_aware=True)
72+
self._log_json_opts = json_util.JSONOptions(
73+
tz_aware=True,
74+
datetime_conversion=DatetimeConversion.DATETIME_AUTO,
75+
)
7276

7377
def run_job(self):
7478
self.collect_slow_operations()
Lines changed: 120 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,120 @@
1+
# (C) Datadog, Inc. 2026-present
2+
# All rights reserved
3+
# Licensed under a 3-clause BSD style license (see LICENSE)
4+
5+
import json
6+
import logging
7+
from datetime import datetime, timezone
8+
from typing import Any
9+
10+
from bson import json_util
11+
from mock import MagicMock
12+
13+
from datadog_checks.mongo.dbm.slow_operations import MongoSlowOperations
14+
15+
# MongoDB 8.0 RSM topology change log with Int64.MIN_VALUE as a $date sentinel
16+
# for "never updated" in the ReplicaSetMonitor.
17+
RSM_TOPOLOGY_CHANGE_LOG = json.dumps(
18+
{
19+
"t": {"$date": "2024-06-01T12:00:00.500+00:00"},
20+
"s": "I",
21+
"c": "NETWORK",
22+
"id": 4333213,
23+
"ctx": "ReplicaSetMonitor-TaskExecutor",
24+
"msg": "RSM Topology Change",
25+
"attr": {
26+
"replicaSet": "rs0",
27+
"newDescription": {
28+
"topologyType": "ReplicaSetWithPrimary",
29+
"servers": [
30+
{
31+
"address": "mongodb-dev1:27017",
32+
"type": "RSPrimary",
33+
"lastUpdateTime": {"$date": {"$numberLong": "-9223372036854775808"}},
34+
"roundTripTime": {"$numberLong": "1234"},
35+
}
36+
],
37+
},
38+
},
39+
}
40+
)
41+
42+
SLOW_QUERY_LOG_TEMPLATE = (
43+
'{{"t":{{"$date":"{timestamp}"}},'
44+
'"s":"I","c":"COMMAND","id":51803,"ctx":"conn50","msg":"Slow query",'
45+
'"attr":{{"type":"command","ns":"test.$cmd",'
46+
'"command":{{"update":"customers","ordered":true,"$db":"test"}},'
47+
'"numYields":0,"reslen":60,"durationMillis":11}}}}'
48+
)
49+
50+
MOCK_SLOW_OPS_CONFIG = {
51+
'enabled': True,
52+
'collection_interval': 10,
53+
'max_operations': 100,
54+
'explain_verbosity': 'queryPlanner',
55+
'explained_operations_cache_maxsize': 5000,
56+
'explained_operations_per_hour_per_query': 10,
57+
'run_sync': True,
58+
}
59+
60+
61+
def _make_slow_query_log(timestamp: str) -> str:
62+
return SLOW_QUERY_LOG_TEMPLATE.format(timestamp=timestamp)
63+
64+
65+
def _make_mock_check():
66+
check = MagicMock()
67+
check._config.slow_operations = MOCK_SLOW_OPS_CONFIG
68+
check._config.timeout = 10000
69+
check._config.min_collection_interval = 15
70+
check._database_autodiscovery._max_databases = 100
71+
check.log = logging.getLogger('test_slow_operations')
72+
return check
73+
74+
75+
class TestSlowOperationsRSMTopologyOverflow:
76+
"""Regression: out-of-range $date values in MongoDB 8.0 RSM topology logs
77+
must not break log parsing or degrade binary search."""
78+
79+
def test_json_parse_rsm_topology_change_log(self):
80+
"""json_util.loads must handle out-of-range $date sentinels without raising."""
81+
slow_ops = MongoSlowOperations(_make_mock_check())
82+
parsed = json_util.loads(RSM_TOPOLOGY_CHANGE_LOG, json_options=slow_ops._log_json_opts)
83+
assert parsed["msg"] == "RSM Topology Change"
84+
85+
def test_binary_search_with_rsm_topology_log_in_middle(self):
86+
"""_binary_search must complete correctly when an RSM topology entry is at the midpoint."""
87+
slow_ops = MongoSlowOperations(_make_mock_check())
88+
89+
logs = [
90+
_make_slow_query_log("2024-06-01T11:00:00.000+00:00"),
91+
_make_slow_query_log("2024-06-01T11:30:00.000+00:00"),
92+
RSM_TOPOLOGY_CHANGE_LOG,
93+
_make_slow_query_log("2024-06-01T12:30:00.000+00:00"),
94+
_make_slow_query_log("2024-06-01T13:00:00.000+00:00"),
95+
]
96+
97+
target_ts = datetime(2024, 6, 1, 12, 15, 0, tzinfo=timezone.utc).timestamp()
98+
result = slow_ops._binary_search(logs, target_ts)
99+
assert result >= 3, f"_binary_search returned {result}, expected >= 3 (bailed out early)"
100+
101+
def test_collect_slow_operations_skips_rsm_topology_without_error(self):
102+
"""RSM topology entries must be skipped via the msg filter, not via exception handling."""
103+
check = MagicMock()
104+
check._config.slow_operations = MOCK_SLOW_OPS_CONFIG
105+
check._config.timeout = 10000
106+
check._config.min_collection_interval = 15
107+
check._database_autodiscovery._max_databases = 100
108+
109+
slow_ops = MongoSlowOperations(check)
110+
check.api_client.get_log_data.return_value = {
111+
"log": [
112+
RSM_TOPOLOGY_CHANGE_LOG,
113+
_make_slow_query_log("2024-06-01T13:00:00.000+00:00"),
114+
]
115+
}
116+
117+
last_ts = datetime(2024, 6, 1, 10, 0, 0, tzinfo=timezone.utc).timestamp()
118+
results = list[Any](slow_ops._collect_slow_operations_from_logs({"test"}, last_ts))
119+
assert len(results) == 1
120+
check.log.error.assert_not_called()

0 commit comments

Comments
 (0)