OLD | NEW |
| (Empty) |
1 # Copyright 2015 The Chromium Authors. All rights reserved. | |
2 # Use of this source code is governed by a BSD-style license that can be | |
3 # found in the LICENSE file. | |
4 | |
5 import logging | |
6 import os | |
7 import random | |
8 import StringIO | |
9 import time | |
10 import unittest | |
11 | |
12 import httplib2 | |
13 import mock | |
14 | |
15 import infra_libs | |
16 from infra_libs.event_mon import config | |
17 from infra_libs.event_mon import router | |
18 from infra_libs.event_mon.protos.chrome_infra_log_pb2 import ChromeInfraEvent | |
19 from infra_libs.event_mon.protos.log_request_lite_pb2 import LogRequestLite | |
20 import infra_libs.event_mon.monitoring | |
21 | |
22 | |
23 DATA_DIR = os.path.join(os.path.dirname(os.path.realpath(__file__)), 'data') | |
24 | |
25 | |
26 class HttpRouterTests(unittest.TestCase): | |
27 def test_without_credentials_smoke(self): | |
28 # Use dry_run to avoid code that deals with http. | |
29 r = router._HttpRouter({}, 'https://any.where', dry_run=True) | |
30 self.assertIsInstance(r._http, infra_libs.InstrumentedHttp) | |
31 | |
32 def test_with_credentials_smoke(self): | |
33 cache = {'service_account_creds': | |
34 os.path.join(DATA_DIR, 'valid_creds.json'), | |
35 'service_accounts_creds_root': 'whatever.the/other/is/absolute'} | |
36 r = router._HttpRouter(cache, 'https://any.where', dry_run=True) | |
37 self.assertIsInstance(r._http, infra_libs.InstrumentedHttp) | |
38 | |
39 def test_with_nonexisting_credentials(self): | |
40 cache = {'service_account_creds': | |
41 os.path.join(DATA_DIR, 'no-such-file-8531.json'), | |
42 'service_accounts_creds_root': 'whatever.the/other/is/absolute'} | |
43 # things should work. | |
44 r = router._HttpRouter(cache, 'https://any.where', dry_run=True) | |
45 self.assertIsInstance(r._http, infra_libs.InstrumentedHttp) | |
46 | |
47 def test_push_smoke(self): | |
48 r = router._HttpRouter({}, 'https://any.where', dry_run=True) | |
49 | |
50 req = LogRequestLite.LogEventLite() | |
51 req.event_time_ms = router.time_ms() | |
52 req.event_code = 1 | |
53 req.event_flow_id = 2 | |
54 self.assertTrue(r.push_event(req)) | |
55 | |
56 def test_push_invalid_event(self): | |
57 r = router._HttpRouter({}, 'https://any.where', dry_run=True) | |
58 self.assertFalse(r.push_event(None)) | |
59 | |
60 def test_invalid_url(self): | |
61 event = LogRequestLite.LogEventLite() | |
62 event.event_time_ms = router.time_ms() | |
63 event.event_code = 1 | |
64 event.event_flow_id = 2 | |
65 | |
66 r = router._HttpRouter({}, 'ftp://any.where', dry_run=True) | |
67 self.assertFalse(r.push_event(event)) | |
68 | |
69 # Below this line, test the send/retry loop. | |
70 def test_push_ok(self): | |
71 # Successfully push event the first time. | |
72 sleep = mock.create_autospec(time.sleep, auto_set=True) | |
73 r = router._HttpRouter({}, 'https://bla.bla', _sleep_fn=sleep) | |
74 r._http = infra_libs.HttpMock([('https://bla.bla', {'status': 200}, '')]) | |
75 | |
76 event = LogRequestLite.LogEventLite() | |
77 event.event_time_ms = router.time_ms() | |
78 event.event_code = 1 | |
79 event.event_flow_id = 2 | |
80 self.assertTrue(r.push_event(event)) | |
81 self.assertEquals(len(sleep.call_args_list), 0) | |
82 | |
83 def test_push_fail(self): | |
84 # Fail to push events even after all retries | |
85 sleep = mock.create_autospec(time.sleep, auto_set=True) | |
86 r = router._HttpRouter({}, 'https://bla.bla', _sleep_fn=sleep) | |
87 r._http = infra_libs.HttpMock([('https://bla.bla', {'status': 403}, '')]) | |
88 | |
89 event = LogRequestLite.LogEventLite() | |
90 event.event_time_ms = router.time_ms() | |
91 event.event_code = 1 | |
92 event.event_flow_id = 2 | |
93 self.assertFalse(r.push_event(event)) | |
94 self.assertEquals(len(sleep.call_args_list), r.try_num) | |
95 | |
96 def test_push_exception(self): | |
97 # Fail to push events even after all retries | |
98 sleep = mock.create_autospec(time.sleep, auto_set=True) | |
99 r = router._HttpRouter({}, 'https://bla.bla', _sleep_fn=sleep) | |
100 | |
101 class FakeHttp(object): | |
102 # pylint: disable=unused-argument | |
103 def request(self, *args, **kwargs): | |
104 raise ValueError() | |
105 | |
106 r._http = FakeHttp() | |
107 | |
108 event = LogRequestLite.LogEventLite() | |
109 event.event_time_ms = router.time_ms() | |
110 event.event_code = 1 | |
111 event.event_flow_id = 2 | |
112 self.assertFalse(r.push_event(event)) | |
113 self.assertEquals(len(sleep.call_args_list), 3) | |
114 | |
115 @mock.patch('logging.debug', autospec=True) | |
116 def test_logs_success(self, logdebug): | |
117 r = router._HttpRouter({}, 'https://bla.bla') | |
118 r._http = infra_libs.HttpMock([('https://bla.bla', {'status': 200}, '')]) | |
119 | |
120 event = LogRequestLite.LogEventLite() | |
121 event.event_time_ms = router.time_ms() | |
122 event.event_code = 1 | |
123 event.event_flow_id = 2 | |
124 self.assertTrue(r.push_event(event)) | |
125 self.assertIn(mock.call('Succeeded POSTing data after %d attempts', 1), | |
126 logdebug.call_args_list) | |
127 | |
128 | |
129 class TextStreamRouterTests(unittest.TestCase): | |
130 def test_stdout_smoke(self): | |
131 event = LogRequestLite.LogEventLite() | |
132 event.event_time_ms = router.time_ms() | |
133 event.event_code = 1 | |
134 event.event_flow_id = 2 | |
135 r = router._TextStreamRouter() | |
136 self.assertTrue(r.push_event(event)) | |
137 | |
138 def test_stringio_stream(self): | |
139 config._cache['default_event'] = ChromeInfraEvent() | |
140 log_event = infra_libs.event_mon.monitoring._get_service_event( | |
141 'START', timestamp_kind='POINT', event_timestamp=1234).log_event() | |
142 | |
143 stream = StringIO.StringIO() | |
144 r = router._TextStreamRouter(stream=stream) | |
145 self.assertTrue(r.push_event(log_event)) | |
146 stream.seek(0) | |
147 output = stream.read() | |
148 self.assertGreater(stream.len, 10) | |
149 # Minimal checking because if this is printed the rest is printed as well | |
150 # unless google.protobuf is completely broken. | |
151 self.assertIn('timestamp_kind: POINT', output) | |
152 | |
153 def test_closed_stream(self): | |
154 event = LogRequestLite.LogEventLite() | |
155 event.event_time_ms = router.time_ms() | |
156 event.event_code = 1 | |
157 event.event_flow_id = 2 | |
158 stream = StringIO.StringIO() | |
159 stream.close() | |
160 r = router._TextStreamRouter(stream=stream) | |
161 self.assertFalse(r.push_event(event)) | |
162 | |
163 | |
164 class LocalFileRouterTests(unittest.TestCase): | |
165 def test_existing_directory(self): | |
166 event = LogRequestLite.LogEventLite() | |
167 event.event_time_ms = router.time_ms() | |
168 event.event_code = 1 | |
169 event.event_flow_id = 2 | |
170 | |
171 with infra_libs.temporary_directory(prefix='event-mon-') as tempdir: | |
172 filename = os.path.join(tempdir, 'output.db') | |
173 r = router._LocalFileRouter(filename, dry_run=False) | |
174 self.assertTrue(r.push_event(event)) | |
175 | |
176 # Check that the file is readable and contains the right data. | |
177 with open(filename, 'rb') as f: | |
178 req_read = LogRequestLite.FromString(f.read()) | |
179 self.assertEqual(len(req_read.log_event), 1) | |
180 event_read = req_read.log_event[0] | |
181 self.assertEqual(event_read.event_time_ms, event.event_time_ms) | |
182 self.assertEqual(event_read.event_code, event.event_code) | |
183 self.assertEqual(event_read.event_flow_id, event.event_flow_id) | |
184 | |
185 def test_existing_directory_dry_run(self): | |
186 event = LogRequestLite.LogEventLite() | |
187 event.event_time_ms = router.time_ms() | |
188 event.event_code = 1 | |
189 event.event_flow_id = 2 | |
190 | |
191 with infra_libs.temporary_directory(prefix='event-mon-') as tempdir: | |
192 filename = os.path.join(tempdir, 'output.db') | |
193 r = router._LocalFileRouter(filename, dry_run=True) | |
194 self.assertTrue(r.push_event(event)) | |
195 | |
196 # Check that the file has not been written | |
197 self.assertFalse(os.path.exists(filename)) | |
198 | |
199 def test_non_existing_directory(self): | |
200 req = LogRequestLite.LogEventLite() | |
201 req.event_time_ms = router.time_ms() | |
202 req.event_code = 1 | |
203 req.event_flow_id = 2 | |
204 r = router._LocalFileRouter( | |
205 os.path.join('non_existing_d1r_31401789', 'output.db'), dry_run=False) | |
206 self.assertFalse(r.push_event(req)) | |
207 | |
208 | |
209 class BackoffTest(unittest.TestCase): | |
210 def test_backoff_time_first_value(self): | |
211 t = router.backoff_time(attempt=0, retry_backoff=2.) | |
212 random.seed(0) | |
213 self.assertTrue(1.5 <= t <= 2.5) | |
214 | |
215 def test_backoff_time_max_value(self): | |
216 t = router.backoff_time(attempt=10, retry_backoff=2., max_delay=5) | |
217 self.assertTrue(abs(t - 5.) < 0.0001) | |
218 | |
219 | |
220 class LoggingStreamRouterTests(unittest.TestCase): | |
221 @mock.patch('logging.log') | |
222 def test_events_are_logged_correctly(self, log_mock): | |
223 logger = router._LoggingStreamRouter() | |
224 events = [] | |
225 for i in range(3): | |
226 event = LogRequestLite.LogEventLite() | |
227 event.event_time_ms = router.time_ms() | |
228 event.event_code = 1 | |
229 event.event_flow_id = 2 | |
230 infra_event = ChromeInfraEvent() | |
231 infra_event.cq_event.issue = str(i + 1) | |
232 event.source_extension = infra_event.SerializeToString() | |
233 events.append(event) | |
234 | |
235 self.assertTrue(logger.push_event(events)) | |
236 | |
237 expected_calls = [ | |
238 ((logging.INFO, | |
239 'Sending event_mon event:\ncq_event {\n issue: "1"\n}\n'),), | |
240 ((logging.INFO, | |
241 'Sending event_mon event:\ncq_event {\n issue: "2"\n}\n'),), | |
242 ((logging.INFO, | |
243 'Sending event_mon event:\ncq_event {\n issue: "3"\n}\n'),)] | |
244 self.assertEqual(log_mock.call_args_list, expected_calls) | |
245 | |
246 @mock.patch('logging.log') | |
247 def test_events_are_logged_with_specified_severity(self, log_mock): | |
248 logger = router._LoggingStreamRouter(logging.WARN) | |
249 event = LogRequestLite.LogEventLite() | |
250 event.event_time_ms = router.time_ms() | |
251 event.event_code = 1 | |
252 event.event_flow_id = 2 | |
253 self.assertTrue(logger.push_event(event)) | |
254 self.assertEqual(log_mock.call_args[0], (logging.WARN, mock.ANY)) | |
255 | |
256 @mock.patch('logging.exception') | |
257 def test_fails_to_log(self, exception_mock): | |
258 logger = router._LoggingStreamRouter(logging.WARN) | |
259 event = LogRequestLite.LogEventLite() | |
260 event.event_time_ms = router.time_ms() | |
261 event.event_code = 1 | |
262 event.event_flow_id = 2 | |
263 event.source_extension = 'not-a-message' | |
264 self.assertFalse(logger.push_event(event)) | |
265 self.assertEqual(exception_mock.call_args[0], ('Unable to log the events',)) | |
OLD | NEW |