Skip to content

Commit a13842f

Browse files
aclark4lifeaclark4life
authored
PYTHON-5778 Add 100% unit test coverage for event_loggers.py (mongodb#2769)
1 parent 8363bf6 commit a13842f

1 file changed

Lines changed: 374 additions & 0 deletions

File tree

‎test/test_event_loggers.py‎

Lines changed: 374 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,374 @@
1+
# Copyright 2026-present MongoDB, Inc.
2+
#
3+
# Licensed under the Apache License, Version 2.0 (the "License");
4+
# you may not use this file except in compliance with the License.
5+
# You may obtain a copy of the License at
6+
#
7+
# http://www.apache.org/licenses/LICENSE-2.0
8+
#
9+
# Unless required by applicable law or agreed to in writing, software
10+
# distributed under the License is distributed on an "AS IS" BASIS,
11+
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12+
# See the License for the specific language governing permissions and
13+
# limitations under the License.
14+
15+
"""Tests for pymongo.event_loggers."""
16+
from __future__ import annotations
17+
18+
import sys
19+
from unittest.mock import MagicMock, patch
20+
21+
sys.path[0:0] = [""]
22+
23+
from test import unittest
24+
25+
from pymongo.event_loggers import (
26+
CommandLogger,
27+
ConnectionPoolLogger,
28+
HeartbeatLogger,
29+
ServerLogger,
30+
TopologyLogger,
31+
)
32+
33+
34+
class TestCommandLogger(unittest.TestCase):
35+
def setUp(self):
36+
self.logger = CommandLogger()
37+
38+
def test_started_logs_info(self):
39+
event = MagicMock()
40+
event.command_name = "find"
41+
event.request_id = 42
42+
event.connection_id = ("localhost", 27017)
43+
with self.assertLogs(level="INFO") as logs:
44+
self.logger.started(event)
45+
log = logs.records[0].getMessage()
46+
self.assertIn("find", log)
47+
self.assertIn("42", log)
48+
self.assertIn("started", log)
49+
50+
def test_succeeded_logs_info(self):
51+
event = MagicMock()
52+
event.command_name = "insert"
53+
event.request_id = 7
54+
event.connection_id = ("localhost", 27017)
55+
event.duration_micros = 500
56+
with self.assertLogs(level="INFO") as logs:
57+
self.logger.succeeded(event)
58+
log = logs.records[0].getMessage()
59+
self.assertIn("insert", log)
60+
self.assertIn("7", log)
61+
self.assertIn("500", log)
62+
self.assertIn("microseconds", log)
63+
self.assertIn("succeeded", log)
64+
65+
def test_failed_logs_info(self):
66+
event = MagicMock()
67+
event.command_name = "delete"
68+
event.request_id = 3
69+
event.connection_id = ("localhost", 27017)
70+
event.duration_micros = 300
71+
with self.assertLogs(level="INFO") as logs:
72+
self.logger.failed(event)
73+
log = logs.records[0].getMessage()
74+
self.assertIn("delete", log)
75+
self.assertIn("3", log)
76+
self.assertIn("300", log)
77+
self.assertIn("microseconds", log)
78+
self.assertIn("failed", log)
79+
80+
81+
class TestServerLogger(unittest.TestCase):
82+
def setUp(self):
83+
self.logger = ServerLogger()
84+
85+
def test_opened_logs_info(self):
86+
event = MagicMock()
87+
event.server_address = ("host1", 27017)
88+
event.topology_id = "topology-abc"
89+
with self.assertLogs(level="INFO") as logs:
90+
self.logger.opened(event)
91+
log = logs.records[0].getMessage()
92+
self.assertIn("host1", log)
93+
self.assertIn("topology-abc", log)
94+
95+
def test_closed_logs_warning(self):
96+
event = MagicMock()
97+
event.server_address = ("host1", 27017)
98+
event.topology_id = "topology-abc"
99+
with self.assertLogs(level="WARNING") as logs:
100+
self.logger.closed(event)
101+
log = logs.records[0].getMessage()
102+
self.assertIn("host1", log)
103+
self.assertIn("topology-abc", log)
104+
105+
def test_description_changed_logs_when_type_changes(self):
106+
event = MagicMock()
107+
event.server_address = ("host1", 27017)
108+
event.previous_description.server_type = 1
109+
event.previous_description.server_type_name = "Unknown"
110+
event.new_description.server_type = 2
111+
event.new_description.server_type_name = "Standalone"
112+
with self.assertLogs(level="INFO") as logs:
113+
self.logger.description_changed(event)
114+
log = logs.records[0].getMessage()
115+
self.assertIn("Unknown", log)
116+
self.assertIn("Standalone", log)
117+
118+
def test_description_changed_no_log_when_type_same(self):
119+
event = MagicMock()
120+
event.previous_description.server_type = 2
121+
event.new_description.server_type = 2
122+
with patch("logging.info") as mock_info:
123+
self.logger.description_changed(event)
124+
mock_info.assert_not_called()
125+
126+
127+
class TestHeartbeatLogger(unittest.TestCase):
128+
def setUp(self):
129+
self.logger = HeartbeatLogger()
130+
131+
def test_started_logs_info(self):
132+
event = MagicMock()
133+
event.connection_id = ("mongo.host", 27017)
134+
with self.assertLogs(level="INFO") as logs:
135+
self.logger.started(event)
136+
log = logs.records[0].getMessage()
137+
self.assertIn("mongo.host", log)
138+
139+
def test_succeeded_logs_info(self):
140+
event = MagicMock()
141+
event.connection_id = ("mongo.host", 27017)
142+
event.reply.document = {"ok": 1, "maxWireVersion": 17}
143+
with self.assertLogs(level="INFO") as logs:
144+
self.logger.succeeded(event)
145+
log = logs.records[0].getMessage()
146+
self.assertIn("mongo.host", log)
147+
self.assertIn("succeeded", log)
148+
self.assertIn("maxWireVersion", log)
149+
150+
def test_failed_logs_warning(self):
151+
event = MagicMock()
152+
event.connection_id = ("mongo.host", 27017)
153+
event.reply = TimeoutError("timed out")
154+
with self.assertLogs(level="WARNING") as logs:
155+
self.logger.failed(event)
156+
log = logs.records[0].getMessage()
157+
self.assertIn("mongo.host", log)
158+
self.assertIn("failed", log)
159+
self.assertIn("timed out", log)
160+
161+
162+
class TestTopologyLogger(unittest.TestCase):
163+
def setUp(self):
164+
self.logger = TopologyLogger()
165+
166+
def test_opened_logs_info(self):
167+
event = MagicMock()
168+
event.topology_id = "topo-1"
169+
with self.assertLogs(level="INFO") as logs:
170+
self.logger.opened(event)
171+
log = logs.records[0].getMessage()
172+
self.assertIn("topo-1", log)
173+
self.assertIn("opened", log)
174+
175+
def test_closed_logs_info(self):
176+
event = MagicMock()
177+
event.topology_id = "topo-1"
178+
with self.assertLogs(level="INFO") as logs:
179+
self.logger.closed(event)
180+
log = logs.records[0].getMessage()
181+
self.assertIn("topo-1", log)
182+
self.assertIn("closed", log)
183+
184+
def test_description_changed_always_logs_update(self):
185+
event = MagicMock()
186+
event.topology_id = "topo-1"
187+
event.previous_description.topology_type = 1
188+
event.new_description.topology_type = 1
189+
event.new_description.has_writable_server.return_value = True
190+
event.new_description.has_readable_server.return_value = True
191+
with self.assertLogs(level="INFO") as logs:
192+
self.logger.description_changed(event)
193+
messages = [r.getMessage() for r in logs.records]
194+
self.assertTrue(any("updated" in m for m in messages))
195+
self.assertTrue(any("topo-1" in m for m in messages))
196+
197+
def test_description_changed_logs_type_change(self):
198+
event = MagicMock()
199+
event.topology_id = "topo-2"
200+
event.previous_description.topology_type = 0
201+
event.previous_description.topology_type_name = "Unknown"
202+
event.new_description.topology_type = 1
203+
event.new_description.topology_type_name = "Single"
204+
event.new_description.has_writable_server.return_value = True
205+
event.new_description.has_readable_server.return_value = True
206+
with self.assertLogs(level="INFO") as logs:
207+
self.logger.description_changed(event)
208+
messages = [r.getMessage() for r in logs.records]
209+
self.assertTrue(any("Unknown" in m and "Single" in m for m in messages))
210+
211+
def test_description_changed_no_type_change_log_when_same(self):
212+
event = MagicMock()
213+
event.topology_id = "topo-1"
214+
event.previous_description.topology_type = 1
215+
event.new_description.topology_type = 1
216+
event.new_description.has_writable_server.return_value = True
217+
event.new_description.has_readable_server.return_value = True
218+
with self.assertLogs(level="INFO") as logs:
219+
self.logger.description_changed(event)
220+
messages = [r.getMessage() for r in logs.records]
221+
self.assertFalse(any("changed type" in m for m in messages))
222+
223+
def test_description_changed_warns_no_writable_server(self):
224+
event = MagicMock()
225+
event.previous_description.topology_type = 1
226+
event.new_description.topology_type = 1
227+
event.new_description.has_writable_server.return_value = False
228+
event.new_description.has_readable_server.return_value = True
229+
with self.assertLogs(level="WARNING") as logs:
230+
self.logger.description_changed(event)
231+
messages = [r.getMessage() for r in logs.records]
232+
self.assertTrue(any("writable" in m for m in messages))
233+
234+
def test_description_changed_warns_no_readable_server(self):
235+
event = MagicMock()
236+
event.previous_description.topology_type = 1
237+
event.new_description.topology_type = 1
238+
event.new_description.has_writable_server.return_value = True
239+
event.new_description.has_readable_server.return_value = False
240+
with self.assertLogs(level="WARNING") as logs:
241+
self.logger.description_changed(event)
242+
messages = [r.getMessage() for r in logs.records]
243+
self.assertTrue(any("readable" in m for m in messages))
244+
245+
def test_description_changed_warns_both_unavailable(self):
246+
event = MagicMock()
247+
event.previous_description.topology_type = 1
248+
event.new_description.topology_type = 1
249+
event.new_description.has_writable_server.return_value = False
250+
event.new_description.has_readable_server.return_value = False
251+
with self.assertLogs(level="WARNING") as logs:
252+
self.logger.description_changed(event)
253+
warning_messages = [r.getMessage() for r in logs.records if r.levelname == "WARNING"]
254+
self.assertEqual(len(warning_messages), 2)
255+
256+
257+
class TestConnectionPoolLogger(unittest.TestCase):
258+
def setUp(self):
259+
self.logger = ConnectionPoolLogger()
260+
261+
def test_pool_created(self):
262+
event = MagicMock()
263+
event.address = ("localhost", 27017)
264+
with self.assertLogs(level="INFO") as logs:
265+
self.logger.pool_created(event)
266+
log = logs.records[0].getMessage()
267+
self.assertIn("pool created", log)
268+
self.assertIn("localhost", log)
269+
270+
def test_pool_ready(self):
271+
event = MagicMock()
272+
event.address = ("localhost", 27017)
273+
with self.assertLogs(level="INFO") as logs:
274+
self.logger.pool_ready(event)
275+
log = logs.records[0].getMessage()
276+
self.assertIn("pool ready", log)
277+
self.assertIn("localhost", log)
278+
279+
def test_pool_cleared(self):
280+
event = MagicMock()
281+
event.address = ("localhost", 27017)
282+
with self.assertLogs(level="INFO") as logs:
283+
self.logger.pool_cleared(event)
284+
log = logs.records[0].getMessage()
285+
self.assertIn("pool cleared", log)
286+
self.assertIn("localhost", log)
287+
288+
def test_pool_closed(self):
289+
event = MagicMock()
290+
event.address = ("localhost", 27017)
291+
with self.assertLogs(level="INFO") as logs:
292+
self.logger.pool_closed(event)
293+
log = logs.records[0].getMessage()
294+
self.assertIn("pool closed", log)
295+
self.assertIn("localhost", log)
296+
297+
def test_connection_created(self):
298+
event = MagicMock()
299+
event.address = ("localhost", 27017)
300+
event.connection_id = 5
301+
with self.assertLogs(level="INFO") as logs:
302+
self.logger.connection_created(event)
303+
log = logs.records[0].getMessage()
304+
self.assertIn("connection created", log)
305+
self.assertIn("5", log)
306+
self.assertIn("localhost", log)
307+
308+
def test_connection_ready(self):
309+
event = MagicMock()
310+
event.address = ("localhost", 27017)
311+
event.connection_id = 5
312+
with self.assertLogs(level="INFO") as logs:
313+
self.logger.connection_ready(event)
314+
log = logs.records[0].getMessage()
315+
self.assertIn("connection setup succeeded", log)
316+
self.assertIn("5", log)
317+
318+
def test_connection_closed(self):
319+
event = MagicMock()
320+
event.address = ("localhost", 27017)
321+
event.connection_id = 5
322+
event.reason = "stale"
323+
with self.assertLogs(level="INFO") as logs:
324+
self.logger.connection_closed(event)
325+
log = logs.records[0].getMessage()
326+
self.assertIn("connection closed", log)
327+
self.assertIn("5", log)
328+
self.assertIn("stale", log)
329+
330+
def test_connection_check_out_started(self):
331+
event = MagicMock()
332+
event.address = ("localhost", 27017)
333+
with self.assertLogs(level="INFO") as logs:
334+
self.logger.connection_check_out_started(event)
335+
log = logs.records[0].getMessage()
336+
self.assertIn("check out started", log)
337+
self.assertIn("localhost", log)
338+
339+
def test_connection_check_out_failed(self):
340+
event = MagicMock()
341+
event.address = ("localhost", 27017)
342+
event.reason = "timeout"
343+
with self.assertLogs(level="INFO") as logs:
344+
self.logger.connection_check_out_failed(event)
345+
log = logs.records[0].getMessage()
346+
self.assertIn("check out failed", log)
347+
self.assertIn("timeout", log)
348+
self.assertIn("localhost", log)
349+
350+
def test_connection_checked_out(self):
351+
event = MagicMock()
352+
event.address = ("localhost", 27017)
353+
event.connection_id = 3
354+
with self.assertLogs(level="INFO") as logs:
355+
self.logger.connection_checked_out(event)
356+
log = logs.records[0].getMessage()
357+
self.assertIn("checked out", log)
358+
self.assertIn("3", log)
359+
self.assertIn("localhost", log)
360+
361+
def test_connection_checked_in(self):
362+
event = MagicMock()
363+
event.address = ("localhost", 27017)
364+
event.connection_id = 3
365+
with self.assertLogs(level="INFO") as logs:
366+
self.logger.connection_checked_in(event)
367+
log = logs.records[0].getMessage()
368+
self.assertIn("checked into", log)
369+
self.assertIn("3", log)
370+
self.assertIn("localhost", log)
371+
372+
373+
if __name__ == "__main__":
374+
unittest.main()

0 commit comments

Comments
 (0)