diff options
Diffstat (limited to 'tests/test_git_trace2_event_log.py')
-rw-r--r-- | tests/test_git_trace2_event_log.py | 725 |
1 files changed, 373 insertions, 352 deletions
diff --git a/tests/test_git_trace2_event_log.py b/tests/test_git_trace2_event_log.py index 7e7dfb7a..a6078d38 100644 --- a/tests/test_git_trace2_event_log.py +++ b/tests/test_git_trace2_event_log.py | |||
@@ -27,361 +27,382 @@ import platform_utils | |||
27 | 27 | ||
28 | 28 | ||
29 | def serverLoggingThread(socket_path, server_ready, received_traces): | 29 | def serverLoggingThread(socket_path, server_ready, received_traces): |
30 | """Helper function to receive logs over a Unix domain socket. | 30 | """Helper function to receive logs over a Unix domain socket. |
31 | |||
32 | Appends received messages on the provided socket and appends to received_traces. | ||
33 | |||
34 | Args: | ||
35 | socket_path: path to a Unix domain socket on which to listen for traces | ||
36 | server_ready: a threading.Condition used to signal to the caller that this thread is ready to | ||
37 | accept connections | ||
38 | received_traces: a list to which received traces will be appended (after decoding to a utf-8 | ||
39 | string). | ||
40 | """ | ||
41 | platform_utils.remove(socket_path, missing_ok=True) | ||
42 | data = b'' | ||
43 | with socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) as sock: | ||
44 | sock.bind(socket_path) | ||
45 | sock.listen(0) | ||
46 | with server_ready: | ||
47 | server_ready.notify() | ||
48 | with sock.accept()[0] as conn: | ||
49 | while True: | ||
50 | recved = conn.recv(4096) | ||
51 | if not recved: | ||
52 | break | ||
53 | data += recved | ||
54 | received_traces.extend(data.decode('utf-8').splitlines()) | ||
55 | 31 | ||
32 | Appends received messages on the provided socket and appends to | ||
33 | received_traces. | ||
56 | 34 | ||
57 | class EventLogTestCase(unittest.TestCase): | 35 | Args: |
58 | """TestCase for the EventLog module.""" | 36 | socket_path: path to a Unix domain socket on which to listen for traces |
59 | 37 | server_ready: a threading.Condition used to signal to the caller that | |
60 | PARENT_SID_KEY = 'GIT_TRACE2_PARENT_SID' | 38 | this thread is ready to accept connections |
61 | PARENT_SID_VALUE = 'parent_sid' | 39 | received_traces: a list to which received traces will be appended (after |
62 | SELF_SID_REGEX = r'repo-\d+T\d+Z-.*' | 40 | decoding to a utf-8 string). |
63 | FULL_SID_REGEX = r'^%s/%s' % (PARENT_SID_VALUE, SELF_SID_REGEX) | ||
64 | |||
65 | def setUp(self): | ||
66 | """Load the event_log module every time.""" | ||
67 | self._event_log_module = None | ||
68 | # By default we initialize with the expected case where | ||
69 | # repo launches us (so GIT_TRACE2_PARENT_SID is set). | ||
70 | env = { | ||
71 | self.PARENT_SID_KEY: self.PARENT_SID_VALUE, | ||
72 | } | ||
73 | self._event_log_module = git_trace2_event_log.EventLog(env=env) | ||
74 | self._log_data = None | ||
75 | |||
76 | def verifyCommonKeys(self, log_entry, expected_event_name=None, full_sid=True): | ||
77 | """Helper function to verify common event log keys.""" | ||
78 | self.assertIn('event', log_entry) | ||
79 | self.assertIn('sid', log_entry) | ||
80 | self.assertIn('thread', log_entry) | ||
81 | self.assertIn('time', log_entry) | ||
82 | |||
83 | # Do basic data format validation. | ||
84 | if expected_event_name: | ||
85 | self.assertEqual(expected_event_name, log_entry['event']) | ||
86 | if full_sid: | ||
87 | self.assertRegex(log_entry['sid'], self.FULL_SID_REGEX) | ||
88 | else: | ||
89 | self.assertRegex(log_entry['sid'], self.SELF_SID_REGEX) | ||
90 | self.assertRegex(log_entry['time'], r'^\d+-\d+-\d+T\d+:\d+:\d+\.\d+Z$') | ||
91 | |||
92 | def readLog(self, log_path): | ||
93 | """Helper function to read log data into a list.""" | ||
94 | log_data = [] | ||
95 | with open(log_path, mode='rb') as f: | ||
96 | for line in f: | ||
97 | log_data.append(json.loads(line)) | ||
98 | return log_data | ||
99 | |||
100 | def remove_prefix(self, s, prefix): | ||
101 | """Return a copy string after removing |prefix| from |s|, if present or the original string.""" | ||
102 | if s.startswith(prefix): | ||
103 | return s[len(prefix):] | ||
104 | else: | ||
105 | return s | ||
106 | |||
107 | def test_initial_state_with_parent_sid(self): | ||
108 | """Test initial state when 'GIT_TRACE2_PARENT_SID' is set by parent.""" | ||
109 | self.assertRegex(self._event_log_module.full_sid, self.FULL_SID_REGEX) | ||
110 | |||
111 | def test_initial_state_no_parent_sid(self): | ||
112 | """Test initial state when 'GIT_TRACE2_PARENT_SID' is not set.""" | ||
113 | # Setup an empty environment dict (no parent sid). | ||
114 | self._event_log_module = git_trace2_event_log.EventLog(env={}) | ||
115 | self.assertRegex(self._event_log_module.full_sid, self.SELF_SID_REGEX) | ||
116 | |||
117 | def test_version_event(self): | ||
118 | """Test 'version' event data is valid. | ||
119 | |||
120 | Verify that the 'version' event is written even when no other | ||
121 | events are addded. | ||
122 | |||
123 | Expected event log: | ||
124 | <version event> | ||
125 | """ | ||
126 | with tempfile.TemporaryDirectory(prefix='event_log_tests') as tempdir: | ||
127 | log_path = self._event_log_module.Write(path=tempdir) | ||
128 | self._log_data = self.readLog(log_path) | ||
129 | |||
130 | # A log with no added events should only have the version entry. | ||
131 | self.assertEqual(len(self._log_data), 1) | ||
132 | version_event = self._log_data[0] | ||
133 | self.verifyCommonKeys(version_event, expected_event_name='version') | ||
134 | # Check for 'version' event specific fields. | ||
135 | self.assertIn('evt', version_event) | ||
136 | self.assertIn('exe', version_event) | ||
137 | # Verify "evt" version field is a string. | ||
138 | self.assertIsInstance(version_event['evt'], str) | ||
139 | |||
140 | def test_start_event(self): | ||
141 | """Test and validate 'start' event data is valid. | ||
142 | |||
143 | Expected event log: | ||
144 | <version event> | ||
145 | <start event> | ||
146 | """ | ||
147 | self._event_log_module.StartEvent() | ||
148 | with tempfile.TemporaryDirectory(prefix='event_log_tests') as tempdir: | ||
149 | log_path = self._event_log_module.Write(path=tempdir) | ||
150 | self._log_data = self.readLog(log_path) | ||
151 | |||
152 | self.assertEqual(len(self._log_data), 2) | ||
153 | start_event = self._log_data[1] | ||
154 | self.verifyCommonKeys(self._log_data[0], expected_event_name='version') | ||
155 | self.verifyCommonKeys(start_event, expected_event_name='start') | ||
156 | # Check for 'start' event specific fields. | ||
157 | self.assertIn('argv', start_event) | ||
158 | self.assertTrue(isinstance(start_event['argv'], list)) | ||
159 | |||
160 | def test_exit_event_result_none(self): | ||
161 | """Test 'exit' event data is valid when result is None. | ||
162 | |||
163 | We expect None result to be converted to 0 in the exit event data. | ||
164 | |||
165 | Expected event log: | ||
166 | <version event> | ||
167 | <exit event> | ||
168 | """ | ||
169 | self._event_log_module.ExitEvent(None) | ||
170 | with tempfile.TemporaryDirectory(prefix='event_log_tests') as tempdir: | ||
171 | log_path = self._event_log_module.Write(path=tempdir) | ||
172 | self._log_data = self.readLog(log_path) | ||
173 | |||
174 | self.assertEqual(len(self._log_data), 2) | ||
175 | exit_event = self._log_data[1] | ||
176 | self.verifyCommonKeys(self._log_data[0], expected_event_name='version') | ||
177 | self.verifyCommonKeys(exit_event, expected_event_name='exit') | ||
178 | # Check for 'exit' event specific fields. | ||
179 | self.assertIn('code', exit_event) | ||
180 | # 'None' result should convert to 0 (successful) return code. | ||
181 | self.assertEqual(exit_event['code'], 0) | ||
182 | |||
183 | def test_exit_event_result_integer(self): | ||
184 | """Test 'exit' event data is valid when result is an integer. | ||
185 | |||
186 | Expected event log: | ||
187 | <version event> | ||
188 | <exit event> | ||
189 | """ | ||
190 | self._event_log_module.ExitEvent(2) | ||
191 | with tempfile.TemporaryDirectory(prefix='event_log_tests') as tempdir: | ||
192 | log_path = self._event_log_module.Write(path=tempdir) | ||
193 | self._log_data = self.readLog(log_path) | ||
194 | |||
195 | self.assertEqual(len(self._log_data), 2) | ||
196 | exit_event = self._log_data[1] | ||
197 | self.verifyCommonKeys(self._log_data[0], expected_event_name='version') | ||
198 | self.verifyCommonKeys(exit_event, expected_event_name='exit') | ||
199 | # Check for 'exit' event specific fields. | ||
200 | self.assertIn('code', exit_event) | ||
201 | self.assertEqual(exit_event['code'], 2) | ||
202 | |||
203 | def test_command_event(self): | ||
204 | """Test and validate 'command' event data is valid. | ||
205 | |||
206 | Expected event log: | ||
207 | <version event> | ||
208 | <command event> | ||
209 | """ | ||
210 | name = 'repo' | ||
211 | subcommands = ['init' 'this'] | ||
212 | self._event_log_module.CommandEvent(name='repo', subcommands=subcommands) | ||
213 | with tempfile.TemporaryDirectory(prefix='event_log_tests') as tempdir: | ||
214 | log_path = self._event_log_module.Write(path=tempdir) | ||
215 | self._log_data = self.readLog(log_path) | ||
216 | |||
217 | self.assertEqual(len(self._log_data), 2) | ||
218 | command_event = self._log_data[1] | ||
219 | self.verifyCommonKeys(self._log_data[0], expected_event_name='version') | ||
220 | self.verifyCommonKeys(command_event, expected_event_name='command') | ||
221 | # Check for 'command' event specific fields. | ||
222 | self.assertIn('name', command_event) | ||
223 | self.assertIn('subcommands', command_event) | ||
224 | self.assertEqual(command_event['name'], name) | ||
225 | self.assertEqual(command_event['subcommands'], subcommands) | ||
226 | |||
227 | def test_def_params_event_repo_config(self): | ||
228 | """Test 'def_params' event data outputs only repo config keys. | ||
229 | |||
230 | Expected event log: | ||
231 | <version event> | ||
232 | <def_param event> | ||
233 | <def_param event> | ||
234 | """ | 41 | """ |
235 | config = { | 42 | platform_utils.remove(socket_path, missing_ok=True) |
236 | 'git.foo': 'bar', | 43 | data = b"" |
237 | 'repo.partialclone': 'true', | 44 | with socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) as sock: |
238 | 'repo.partialclonefilter': 'blob:none', | 45 | sock.bind(socket_path) |
239 | } | 46 | sock.listen(0) |
240 | self._event_log_module.DefParamRepoEvents(config) | ||
241 | |||
242 | with tempfile.TemporaryDirectory(prefix='event_log_tests') as tempdir: | ||
243 | log_path = self._event_log_module.Write(path=tempdir) | ||
244 | self._log_data = self.readLog(log_path) | ||
245 | |||
246 | self.assertEqual(len(self._log_data), 3) | ||
247 | def_param_events = self._log_data[1:] | ||
248 | self.verifyCommonKeys(self._log_data[0], expected_event_name='version') | ||
249 | |||
250 | for event in def_param_events: | ||
251 | self.verifyCommonKeys(event, expected_event_name='def_param') | ||
252 | # Check for 'def_param' event specific fields. | ||
253 | self.assertIn('param', event) | ||
254 | self.assertIn('value', event) | ||
255 | self.assertTrue(event['param'].startswith('repo.')) | ||
256 | |||
257 | def test_def_params_event_no_repo_config(self): | ||
258 | """Test 'def_params' event data won't output non-repo config keys. | ||
259 | |||
260 | Expected event log: | ||
261 | <version event> | ||
262 | """ | ||
263 | config = { | ||
264 | 'git.foo': 'bar', | ||
265 | 'git.core.foo2': 'baz', | ||
266 | } | ||
267 | self._event_log_module.DefParamRepoEvents(config) | ||
268 | |||
269 | with tempfile.TemporaryDirectory(prefix='event_log_tests') as tempdir: | ||
270 | log_path = self._event_log_module.Write(path=tempdir) | ||
271 | self._log_data = self.readLog(log_path) | ||
272 | |||
273 | self.assertEqual(len(self._log_data), 1) | ||
274 | self.verifyCommonKeys(self._log_data[0], expected_event_name='version') | ||
275 | |||
276 | def test_data_event_config(self): | ||
277 | """Test 'data' event data outputs all config keys. | ||
278 | |||
279 | Expected event log: | ||
280 | <version event> | ||
281 | <data event> | ||
282 | <data event> | ||
283 | """ | ||
284 | config = { | ||
285 | 'git.foo': 'bar', | ||
286 | 'repo.partialclone': 'false', | ||
287 | 'repo.syncstate.superproject.hassuperprojecttag': 'true', | ||
288 | 'repo.syncstate.superproject.sys.argv': ['--', 'sync', 'protobuf'], | ||
289 | } | ||
290 | prefix_value = 'prefix' | ||
291 | self._event_log_module.LogDataConfigEvents(config, prefix_value) | ||
292 | |||
293 | with tempfile.TemporaryDirectory(prefix='event_log_tests') as tempdir: | ||
294 | log_path = self._event_log_module.Write(path=tempdir) | ||
295 | self._log_data = self.readLog(log_path) | ||
296 | |||
297 | self.assertEqual(len(self._log_data), 5) | ||
298 | data_events = self._log_data[1:] | ||
299 | self.verifyCommonKeys(self._log_data[0], expected_event_name='version') | ||
300 | |||
301 | for event in data_events: | ||
302 | self.verifyCommonKeys(event) | ||
303 | # Check for 'data' event specific fields. | ||
304 | self.assertIn('key', event) | ||
305 | self.assertIn('value', event) | ||
306 | key = event['key'] | ||
307 | key = self.remove_prefix(key, f'{prefix_value}/') | ||
308 | value = event['value'] | ||
309 | self.assertEqual(self._event_log_module.GetDataEventName(value), event['event']) | ||
310 | self.assertTrue(key in config and value == config[key]) | ||
311 | |||
312 | def test_error_event(self): | ||
313 | """Test and validate 'error' event data is valid. | ||
314 | |||
315 | Expected event log: | ||
316 | <version event> | ||
317 | <error event> | ||
318 | """ | ||
319 | msg = 'invalid option: --cahced' | ||
320 | fmt = 'invalid option: %s' | ||
321 | self._event_log_module.ErrorEvent(msg, fmt) | ||
322 | with tempfile.TemporaryDirectory(prefix='event_log_tests') as tempdir: | ||
323 | log_path = self._event_log_module.Write(path=tempdir) | ||
324 | self._log_data = self.readLog(log_path) | ||
325 | |||
326 | self.assertEqual(len(self._log_data), 2) | ||
327 | error_event = self._log_data[1] | ||
328 | self.verifyCommonKeys(self._log_data[0], expected_event_name='version') | ||
329 | self.verifyCommonKeys(error_event, expected_event_name='error') | ||
330 | # Check for 'error' event specific fields. | ||
331 | self.assertIn('msg', error_event) | ||
332 | self.assertIn('fmt', error_event) | ||
333 | self.assertEqual(error_event['msg'], msg) | ||
334 | self.assertEqual(error_event['fmt'], fmt) | ||
335 | |||
336 | def test_write_with_filename(self): | ||
337 | """Test Write() with a path to a file exits with None.""" | ||
338 | self.assertIsNone(self._event_log_module.Write(path='path/to/file')) | ||
339 | |||
340 | def test_write_with_git_config(self): | ||
341 | """Test Write() uses the git config path when 'git config' call succeeds.""" | ||
342 | with tempfile.TemporaryDirectory(prefix='event_log_tests') as tempdir: | ||
343 | with mock.patch.object(self._event_log_module, | ||
344 | '_GetEventTargetPath', return_value=tempdir): | ||
345 | self.assertEqual(os.path.dirname(self._event_log_module.Write()), tempdir) | ||
346 | |||
347 | def test_write_no_git_config(self): | ||
348 | """Test Write() with no git config variable present exits with None.""" | ||
349 | with mock.patch.object(self._event_log_module, | ||
350 | '_GetEventTargetPath', return_value=None): | ||
351 | self.assertIsNone(self._event_log_module.Write()) | ||
352 | |||
353 | def test_write_non_string(self): | ||
354 | """Test Write() with non-string type for |path| throws TypeError.""" | ||
355 | with self.assertRaises(TypeError): | ||
356 | self._event_log_module.Write(path=1234) | ||
357 | |||
358 | def test_write_socket(self): | ||
359 | """Test Write() with Unix domain socket for |path| and validate received traces.""" | ||
360 | received_traces = [] | ||
361 | with tempfile.TemporaryDirectory(prefix='test_server_sockets') as tempdir: | ||
362 | socket_path = os.path.join(tempdir, "server.sock") | ||
363 | server_ready = threading.Condition() | ||
364 | # Start "server" listening on Unix domain socket at socket_path. | ||
365 | try: | ||
366 | server_thread = threading.Thread( | ||
367 | target=serverLoggingThread, | ||
368 | args=(socket_path, server_ready, received_traces)) | ||
369 | server_thread.start() | ||
370 | |||
371 | with server_ready: | 47 | with server_ready: |
372 | server_ready.wait(timeout=120) | 48 | server_ready.notify() |
49 | with sock.accept()[0] as conn: | ||
50 | while True: | ||
51 | recved = conn.recv(4096) | ||
52 | if not recved: | ||
53 | break | ||
54 | data += recved | ||
55 | received_traces.extend(data.decode("utf-8").splitlines()) | ||
56 | |||
373 | 57 | ||
58 | class EventLogTestCase(unittest.TestCase): | ||
59 | """TestCase for the EventLog module.""" | ||
60 | |||
61 | PARENT_SID_KEY = "GIT_TRACE2_PARENT_SID" | ||
62 | PARENT_SID_VALUE = "parent_sid" | ||
63 | SELF_SID_REGEX = r"repo-\d+T\d+Z-.*" | ||
64 | FULL_SID_REGEX = r"^%s/%s" % (PARENT_SID_VALUE, SELF_SID_REGEX) | ||
65 | |||
66 | def setUp(self): | ||
67 | """Load the event_log module every time.""" | ||
68 | self._event_log_module = None | ||
69 | # By default we initialize with the expected case where | ||
70 | # repo launches us (so GIT_TRACE2_PARENT_SID is set). | ||
71 | env = { | ||
72 | self.PARENT_SID_KEY: self.PARENT_SID_VALUE, | ||
73 | } | ||
74 | self._event_log_module = git_trace2_event_log.EventLog(env=env) | ||
75 | self._log_data = None | ||
76 | |||
77 | def verifyCommonKeys( | ||
78 | self, log_entry, expected_event_name=None, full_sid=True | ||
79 | ): | ||
80 | """Helper function to verify common event log keys.""" | ||
81 | self.assertIn("event", log_entry) | ||
82 | self.assertIn("sid", log_entry) | ||
83 | self.assertIn("thread", log_entry) | ||
84 | self.assertIn("time", log_entry) | ||
85 | |||
86 | # Do basic data format validation. | ||
87 | if expected_event_name: | ||
88 | self.assertEqual(expected_event_name, log_entry["event"]) | ||
89 | if full_sid: | ||
90 | self.assertRegex(log_entry["sid"], self.FULL_SID_REGEX) | ||
91 | else: | ||
92 | self.assertRegex(log_entry["sid"], self.SELF_SID_REGEX) | ||
93 | self.assertRegex(log_entry["time"], r"^\d+-\d+-\d+T\d+:\d+:\d+\.\d+Z$") | ||
94 | |||
95 | def readLog(self, log_path): | ||
96 | """Helper function to read log data into a list.""" | ||
97 | log_data = [] | ||
98 | with open(log_path, mode="rb") as f: | ||
99 | for line in f: | ||
100 | log_data.append(json.loads(line)) | ||
101 | return log_data | ||
102 | |||
103 | def remove_prefix(self, s, prefix): | ||
104 | """Return a copy string after removing |prefix| from |s|, if present or | ||
105 | the original string.""" | ||
106 | if s.startswith(prefix): | ||
107 | return s[len(prefix) :] | ||
108 | else: | ||
109 | return s | ||
110 | |||
111 | def test_initial_state_with_parent_sid(self): | ||
112 | """Test initial state when 'GIT_TRACE2_PARENT_SID' is set by parent.""" | ||
113 | self.assertRegex(self._event_log_module.full_sid, self.FULL_SID_REGEX) | ||
114 | |||
115 | def test_initial_state_no_parent_sid(self): | ||
116 | """Test initial state when 'GIT_TRACE2_PARENT_SID' is not set.""" | ||
117 | # Setup an empty environment dict (no parent sid). | ||
118 | self._event_log_module = git_trace2_event_log.EventLog(env={}) | ||
119 | self.assertRegex(self._event_log_module.full_sid, self.SELF_SID_REGEX) | ||
120 | |||
121 | def test_version_event(self): | ||
122 | """Test 'version' event data is valid. | ||
123 | |||
124 | Verify that the 'version' event is written even when no other | ||
125 | events are addded. | ||
126 | |||
127 | Expected event log: | ||
128 | <version event> | ||
129 | """ | ||
130 | with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: | ||
131 | log_path = self._event_log_module.Write(path=tempdir) | ||
132 | self._log_data = self.readLog(log_path) | ||
133 | |||
134 | # A log with no added events should only have the version entry. | ||
135 | self.assertEqual(len(self._log_data), 1) | ||
136 | version_event = self._log_data[0] | ||
137 | self.verifyCommonKeys(version_event, expected_event_name="version") | ||
138 | # Check for 'version' event specific fields. | ||
139 | self.assertIn("evt", version_event) | ||
140 | self.assertIn("exe", version_event) | ||
141 | # Verify "evt" version field is a string. | ||
142 | self.assertIsInstance(version_event["evt"], str) | ||
143 | |||
144 | def test_start_event(self): | ||
145 | """Test and validate 'start' event data is valid. | ||
146 | |||
147 | Expected event log: | ||
148 | <version event> | ||
149 | <start event> | ||
150 | """ | ||
374 | self._event_log_module.StartEvent() | 151 | self._event_log_module.StartEvent() |
375 | path = self._event_log_module.Write(path=f'af_unix:{socket_path}') | 152 | with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: |
376 | finally: | 153 | log_path = self._event_log_module.Write(path=tempdir) |
377 | server_thread.join(timeout=5) | 154 | self._log_data = self.readLog(log_path) |
378 | 155 | ||
379 | self.assertEqual(path, f'af_unix:stream:{socket_path}') | 156 | self.assertEqual(len(self._log_data), 2) |
380 | self.assertEqual(len(received_traces), 2) | 157 | start_event = self._log_data[1] |
381 | version_event = json.loads(received_traces[0]) | 158 | self.verifyCommonKeys(self._log_data[0], expected_event_name="version") |
382 | start_event = json.loads(received_traces[1]) | 159 | self.verifyCommonKeys(start_event, expected_event_name="start") |
383 | self.verifyCommonKeys(version_event, expected_event_name='version') | 160 | # Check for 'start' event specific fields. |
384 | self.verifyCommonKeys(start_event, expected_event_name='start') | 161 | self.assertIn("argv", start_event) |
385 | # Check for 'start' event specific fields. | 162 | self.assertTrue(isinstance(start_event["argv"], list)) |
386 | self.assertIn('argv', start_event) | 163 | |
387 | self.assertIsInstance(start_event['argv'], list) | 164 | def test_exit_event_result_none(self): |
165 | """Test 'exit' event data is valid when result is None. | ||
166 | |||
167 | We expect None result to be converted to 0 in the exit event data. | ||
168 | |||
169 | Expected event log: | ||
170 | <version event> | ||
171 | <exit event> | ||
172 | """ | ||
173 | self._event_log_module.ExitEvent(None) | ||
174 | with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: | ||
175 | log_path = self._event_log_module.Write(path=tempdir) | ||
176 | self._log_data = self.readLog(log_path) | ||
177 | |||
178 | self.assertEqual(len(self._log_data), 2) | ||
179 | exit_event = self._log_data[1] | ||
180 | self.verifyCommonKeys(self._log_data[0], expected_event_name="version") | ||
181 | self.verifyCommonKeys(exit_event, expected_event_name="exit") | ||
182 | # Check for 'exit' event specific fields. | ||
183 | self.assertIn("code", exit_event) | ||
184 | # 'None' result should convert to 0 (successful) return code. | ||
185 | self.assertEqual(exit_event["code"], 0) | ||
186 | |||
187 | def test_exit_event_result_integer(self): | ||
188 | """Test 'exit' event data is valid when result is an integer. | ||
189 | |||
190 | Expected event log: | ||
191 | <version event> | ||
192 | <exit event> | ||
193 | """ | ||
194 | self._event_log_module.ExitEvent(2) | ||
195 | with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: | ||
196 | log_path = self._event_log_module.Write(path=tempdir) | ||
197 | self._log_data = self.readLog(log_path) | ||
198 | |||
199 | self.assertEqual(len(self._log_data), 2) | ||
200 | exit_event = self._log_data[1] | ||
201 | self.verifyCommonKeys(self._log_data[0], expected_event_name="version") | ||
202 | self.verifyCommonKeys(exit_event, expected_event_name="exit") | ||
203 | # Check for 'exit' event specific fields. | ||
204 | self.assertIn("code", exit_event) | ||
205 | self.assertEqual(exit_event["code"], 2) | ||
206 | |||
207 | def test_command_event(self): | ||
208 | """Test and validate 'command' event data is valid. | ||
209 | |||
210 | Expected event log: | ||
211 | <version event> | ||
212 | <command event> | ||
213 | """ | ||
214 | name = "repo" | ||
215 | subcommands = ["init" "this"] | ||
216 | self._event_log_module.CommandEvent( | ||
217 | name="repo", subcommands=subcommands | ||
218 | ) | ||
219 | with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: | ||
220 | log_path = self._event_log_module.Write(path=tempdir) | ||
221 | self._log_data = self.readLog(log_path) | ||
222 | |||
223 | self.assertEqual(len(self._log_data), 2) | ||
224 | command_event = self._log_data[1] | ||
225 | self.verifyCommonKeys(self._log_data[0], expected_event_name="version") | ||
226 | self.verifyCommonKeys(command_event, expected_event_name="command") | ||
227 | # Check for 'command' event specific fields. | ||
228 | self.assertIn("name", command_event) | ||
229 | self.assertIn("subcommands", command_event) | ||
230 | self.assertEqual(command_event["name"], name) | ||
231 | self.assertEqual(command_event["subcommands"], subcommands) | ||
232 | |||
233 | def test_def_params_event_repo_config(self): | ||
234 | """Test 'def_params' event data outputs only repo config keys. | ||
235 | |||
236 | Expected event log: | ||
237 | <version event> | ||
238 | <def_param event> | ||
239 | <def_param event> | ||
240 | """ | ||
241 | config = { | ||
242 | "git.foo": "bar", | ||
243 | "repo.partialclone": "true", | ||
244 | "repo.partialclonefilter": "blob:none", | ||
245 | } | ||
246 | self._event_log_module.DefParamRepoEvents(config) | ||
247 | |||
248 | with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: | ||
249 | log_path = self._event_log_module.Write(path=tempdir) | ||
250 | self._log_data = self.readLog(log_path) | ||
251 | |||
252 | self.assertEqual(len(self._log_data), 3) | ||
253 | def_param_events = self._log_data[1:] | ||
254 | self.verifyCommonKeys(self._log_data[0], expected_event_name="version") | ||
255 | |||
256 | for event in def_param_events: | ||
257 | self.verifyCommonKeys(event, expected_event_name="def_param") | ||
258 | # Check for 'def_param' event specific fields. | ||
259 | self.assertIn("param", event) | ||
260 | self.assertIn("value", event) | ||
261 | self.assertTrue(event["param"].startswith("repo.")) | ||
262 | |||
263 | def test_def_params_event_no_repo_config(self): | ||
264 | """Test 'def_params' event data won't output non-repo config keys. | ||
265 | |||
266 | Expected event log: | ||
267 | <version event> | ||
268 | """ | ||
269 | config = { | ||
270 | "git.foo": "bar", | ||
271 | "git.core.foo2": "baz", | ||
272 | } | ||
273 | self._event_log_module.DefParamRepoEvents(config) | ||
274 | |||
275 | with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: | ||
276 | log_path = self._event_log_module.Write(path=tempdir) | ||
277 | self._log_data = self.readLog(log_path) | ||
278 | |||
279 | self.assertEqual(len(self._log_data), 1) | ||
280 | self.verifyCommonKeys(self._log_data[0], expected_event_name="version") | ||
281 | |||
282 | def test_data_event_config(self): | ||
283 | """Test 'data' event data outputs all config keys. | ||
284 | |||
285 | Expected event log: | ||
286 | <version event> | ||
287 | <data event> | ||
288 | <data event> | ||
289 | """ | ||
290 | config = { | ||
291 | "git.foo": "bar", | ||
292 | "repo.partialclone": "false", | ||
293 | "repo.syncstate.superproject.hassuperprojecttag": "true", | ||
294 | "repo.syncstate.superproject.sys.argv": ["--", "sync", "protobuf"], | ||
295 | } | ||
296 | prefix_value = "prefix" | ||
297 | self._event_log_module.LogDataConfigEvents(config, prefix_value) | ||
298 | |||
299 | with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: | ||
300 | log_path = self._event_log_module.Write(path=tempdir) | ||
301 | self._log_data = self.readLog(log_path) | ||
302 | |||
303 | self.assertEqual(len(self._log_data), 5) | ||
304 | data_events = self._log_data[1:] | ||
305 | self.verifyCommonKeys(self._log_data[0], expected_event_name="version") | ||
306 | |||
307 | for event in data_events: | ||
308 | self.verifyCommonKeys(event) | ||
309 | # Check for 'data' event specific fields. | ||
310 | self.assertIn("key", event) | ||
311 | self.assertIn("value", event) | ||
312 | key = event["key"] | ||
313 | key = self.remove_prefix(key, f"{prefix_value}/") | ||
314 | value = event["value"] | ||
315 | self.assertEqual( | ||
316 | self._event_log_module.GetDataEventName(value), event["event"] | ||
317 | ) | ||
318 | self.assertTrue(key in config and value == config[key]) | ||
319 | |||
320 | def test_error_event(self): | ||
321 | """Test and validate 'error' event data is valid. | ||
322 | |||
323 | Expected event log: | ||
324 | <version event> | ||
325 | <error event> | ||
326 | """ | ||
327 | msg = "invalid option: --cahced" | ||
328 | fmt = "invalid option: %s" | ||
329 | self._event_log_module.ErrorEvent(msg, fmt) | ||
330 | with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: | ||
331 | log_path = self._event_log_module.Write(path=tempdir) | ||
332 | self._log_data = self.readLog(log_path) | ||
333 | |||
334 | self.assertEqual(len(self._log_data), 2) | ||
335 | error_event = self._log_data[1] | ||
336 | self.verifyCommonKeys(self._log_data[0], expected_event_name="version") | ||
337 | self.verifyCommonKeys(error_event, expected_event_name="error") | ||
338 | # Check for 'error' event specific fields. | ||
339 | self.assertIn("msg", error_event) | ||
340 | self.assertIn("fmt", error_event) | ||
341 | self.assertEqual(error_event["msg"], msg) | ||
342 | self.assertEqual(error_event["fmt"], fmt) | ||
343 | |||
344 | def test_write_with_filename(self): | ||
345 | """Test Write() with a path to a file exits with None.""" | ||
346 | self.assertIsNone(self._event_log_module.Write(path="path/to/file")) | ||
347 | |||
348 | def test_write_with_git_config(self): | ||
349 | """Test Write() uses the git config path when 'git config' call | ||
350 | succeeds.""" | ||
351 | with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: | ||
352 | with mock.patch.object( | ||
353 | self._event_log_module, | ||
354 | "_GetEventTargetPath", | ||
355 | return_value=tempdir, | ||
356 | ): | ||
357 | self.assertEqual( | ||
358 | os.path.dirname(self._event_log_module.Write()), tempdir | ||
359 | ) | ||
360 | |||
361 | def test_write_no_git_config(self): | ||
362 | """Test Write() with no git config variable present exits with None.""" | ||
363 | with mock.patch.object( | ||
364 | self._event_log_module, "_GetEventTargetPath", return_value=None | ||
365 | ): | ||
366 | self.assertIsNone(self._event_log_module.Write()) | ||
367 | |||
368 | def test_write_non_string(self): | ||
369 | """Test Write() with non-string type for |path| throws TypeError.""" | ||
370 | with self.assertRaises(TypeError): | ||
371 | self._event_log_module.Write(path=1234) | ||
372 | |||
373 | def test_write_socket(self): | ||
374 | """Test Write() with Unix domain socket for |path| and validate received | ||
375 | traces.""" | ||
376 | received_traces = [] | ||
377 | with tempfile.TemporaryDirectory( | ||
378 | prefix="test_server_sockets" | ||
379 | ) as tempdir: | ||
380 | socket_path = os.path.join(tempdir, "server.sock") | ||
381 | server_ready = threading.Condition() | ||
382 | # Start "server" listening on Unix domain socket at socket_path. | ||
383 | try: | ||
384 | server_thread = threading.Thread( | ||
385 | target=serverLoggingThread, | ||
386 | args=(socket_path, server_ready, received_traces), | ||
387 | ) | ||
388 | server_thread.start() | ||
389 | |||
390 | with server_ready: | ||
391 | server_ready.wait(timeout=120) | ||
392 | |||
393 | self._event_log_module.StartEvent() | ||
394 | path = self._event_log_module.Write( | ||
395 | path=f"af_unix:{socket_path}" | ||
396 | ) | ||
397 | finally: | ||
398 | server_thread.join(timeout=5) | ||
399 | |||
400 | self.assertEqual(path, f"af_unix:stream:{socket_path}") | ||
401 | self.assertEqual(len(received_traces), 2) | ||
402 | version_event = json.loads(received_traces[0]) | ||
403 | start_event = json.loads(received_traces[1]) | ||
404 | self.verifyCommonKeys(version_event, expected_event_name="version") | ||
405 | self.verifyCommonKeys(start_event, expected_event_name="start") | ||
406 | # Check for 'start' event specific fields. | ||
407 | self.assertIn("argv", start_event) | ||
408 | self.assertIsInstance(start_event["argv"], list) | ||