def push_event(self, log_events):
"""Enqueue event to push to the collection service.
This method offers no guarantee on return that the event have been pushed
externally, as some buffering can take place.
Args:
log_events (LogRequestLite.LogEventLite or list/tuple of): events.
Returns:
success (bool): False if an error happened. True means 'event accepted',
but NOT 'event successfully pushed to the remote'.
"""
if isinstance(log_events, LogRequestLite.LogEventLite):
log_events = (log_events, )
if not isinstance(log_events, (list, tuple)):
logging.error(
'Invalid type for "event", should be LogEventLite or '
'list of. Got %s' % str(type(log_events)))
return False
request_p = LogRequestLite()
request_p.log_source_name = 'CHROME_INFRA'
request_p.log_event.extend(log_events) # copies the protobuf
# Sets the sending time here for safety, _send_to_endpoint should change it
# if needed.
request_p.request_time_ms = time_ms()
return self._send_to_endpoint(request_p)
def push_event(self, log_events):
"""Enqueue event to push to the collection service.
This method offers no guarantee on return that the event have been pushed
externally, as some buffering can take place.
Args:
log_events (LogRequestLite.LogEventLite or list/tuple of): events.
Returns:
success (bool): False if an error happened. True means 'event accepted',
but NOT 'event successfully pushed to the remote'.
"""
if isinstance(log_events, LogRequestLite.LogEventLite):
log_events = (log_events,)
if not isinstance(log_events, (list, tuple)):
logging.error('Invalid type for "event", should be LogEventLite or '
'list of. Got %s' % str(type(log_events)))
return False
request_p = LogRequestLite()
request_p.log_source_name = 'CHROME_INFRA'
request_p.log_event.extend(log_events) # copies the protobuf
# Sets the sending time here for safety, _send_to_endpoint should change it
# if needed.
request_p.request_time_ms = time_ms()
return self._send_to_endpoint(request_p)
def test_stdout_smoke(self):
event = LogRequestLite.LogEventLite()
event.event_time_ms = router.time_ms()
event.event_code = 1
event.event_flow_id = 2
r = router._TextStreamRouter()
self.assertTrue(r.push_event(event))
def test_events_are_logged_with_specified_severity(self, log_mock):
logger = router._LoggingStreamRouter(logging.WARN)
event = LogRequestLite.LogEventLite()
event.event_time_ms = router.time_ms()
event.event_code = 1
event.event_flow_id = 2
self.assertTrue(logger.push_event(event))
self.assertEqual(log_mock.call_args[0], (logging.WARN, mock.ANY))
def test_invalid_url(self):
event = LogRequestLite.LogEventLite()
event.event_time_ms = router.time_ms()
event.event_code = 1
event.event_flow_id = 2
r = router._HttpRouter({}, 'ftp://any.where', dry_run=True)
self.assertFalse(r.push_event(event))
def test_push_smoke(self):
r = router._HttpRouter({}, 'https://any.where', dry_run=True)
req = LogRequestLite.LogEventLite()
req.event_time_ms = router.time_ms()
req.event_code = 1
req.event_flow_id = 2
self.assertTrue(r.push_event(req))
def test_non_existing_directory(self):
req = LogRequestLite.LogEventLite()
req.event_time_ms = router.time_ms()
req.event_code = 1
req.event_flow_id = 2
r = router._LocalFileRouter(os.path.join('non_existing_d1r_31401789',
'output.db'),
dry_run=False)
self.assertFalse(r.push_event(req))
def test_closed_stream(self):
event = LogRequestLite.LogEventLite()
event.event_time_ms = router.time_ms()
event.event_code = 1
event.event_flow_id = 2
stream = StringIO.StringIO()
stream.close()
r = router._TextStreamRouter(stream=stream)
self.assertFalse(r.push_event(event))
def test_existing_directory(self):
event = LogRequestLite.LogEventLite()
event.event_time_ms = router.time_ms()
event.event_code = 1
event.event_flow_id = 2
with infra_libs.temporary_directory(prefix='event-mon-') as tempdir:
filename = os.path.join(tempdir, 'output.db')
r = router._LocalFileRouter(filename, dry_run=False)
self.assertTrue(r.push_event(event))
# Check that the file is readable and contains the right data.
with open(filename, 'rb') as f:
req_read = LogRequestLite.FromString(f.read())
self.assertEqual(len(req_read.log_event), 1)
event_read = req_read.log_event[0]
self.assertEqual(event_read.event_time_ms, event.event_time_ms)
self.assertEqual(event_read.event_code, event.event_code)
self.assertEqual(event_read.event_flow_id, event.event_flow_id)
def test_fails_to_log(self, exception_mock):
logger = router._LoggingStreamRouter(logging.WARN)
event = LogRequestLite.LogEventLite()
event.event_time_ms = router.time_ms()
event.event_code = 1
event.event_flow_id = 2
event.source_extension = 'not-a-message'
self.assertFalse(logger.push_event(event))
self.assertEqual(exception_mock.call_args[0],
('Unable to log the events', ))
def test_existing_directory_dry_run(self):
event = LogRequestLite.LogEventLite()
event.event_time_ms = router.time_ms()
event.event_code = 1
event.event_flow_id = 2
with infra_libs.temporary_directory(prefix='event-mon-') as tempdir:
filename = os.path.join(tempdir, 'output.db')
r = router._LocalFileRouter(filename, dry_run=True)
self.assertTrue(r.push_event(event))
# Check that the file has not been written
self.assertFalse(os.path.exists(filename))
def test_logs_success(self, logdebug):
r = router._HttpRouter({}, 'https://bla.bla')
r._http = infra_libs.HttpMock([('https://bla.bla', {
'status': 200
}, '')])
event = LogRequestLite.LogEventLite()
event.event_time_ms = router.time_ms()
event.event_code = 1
event.event_flow_id = 2
self.assertTrue(r.push_event(event))
self.assertIn(mock.call('Succeeded POSTing data after %d attempts', 1),
logdebug.call_args_list)
def test_push_fail(self):
# Fail to push events even after all retries
sleep = mock.create_autospec(time.sleep, auto_set=True)
r = router._HttpRouter({}, 'https://bla.bla', _sleep_fn=sleep)
r._http = infra_libs.HttpMock([('https://bla.bla', {
'status': 403
}, '')])
event = LogRequestLite.LogEventLite()
event.event_time_ms = router.time_ms()
event.event_code = 1
event.event_flow_id = 2
self.assertFalse(r.push_event(event))
self.assertEquals(len(sleep.call_args_list), r.try_num)
def test_push_ok(self):
# Successfully push event the first time.
sleep = mock.create_autospec(time.sleep, auto_set=True)
r = router._HttpRouter({}, 'https://bla.bla', _sleep_fn=sleep)
r._http = infra_libs.HttpMock([('https://bla.bla', {
'status': 200
}, '')])
event = LogRequestLite.LogEventLite()
event.event_time_ms = router.time_ms()
event.event_code = 1
event.event_flow_id = 2
self.assertTrue(r.push_event(event))
self.assertEquals(len(sleep.call_args_list), 0)
def test_push_exception(self):
# Fail to push events even after all retries
sleep = mock.create_autospec(time.sleep, auto_set=True)
r = router._HttpRouter({}, 'https://bla.bla', _sleep_fn=sleep)
class FakeHttp(object):
# pylint: disable=unused-argument
def request(self, *args, **kwargs):
raise ValueError()
r._http = FakeHttp()
event = LogRequestLite.LogEventLite()
event.event_time_ms = router.time_ms()
event.event_code = 1
event.event_flow_id = 2
self.assertFalse(r.push_event(event))
self.assertEquals(len(sleep.call_args_list), 3)
def _get_log_event_lite(chrome_infra_event, event_timestamp=None):
"""Wraps a ChromeInfraEvent into a LogEventLite.
Args:
event_timestamp (int or float): timestamp of when the event happened
as a number of milliseconds since the epoch. If None, the current time
is used.
Returns:
log_event (log_request_lite_pb2.LogRequestLite.LogEventLite):
"""
if not isinstance(event_timestamp, (int, float, None.__class__ )):
logging.error('Invalid type for event_timestamp. Needs a number, got %s',
type(event_timestamp))
return None
log_event = LogRequestLite.LogEventLite()
log_event.event_time_ms = int(event_timestamp or router.time_ms())
log_event.source_extension = chrome_infra_event.SerializeToString()
return log_event
def test_events_are_logged_correctly(self, log_mock):
logger = router._LoggingStreamRouter()
events = []
for i in range(3):
event = LogRequestLite.LogEventLite()
event.event_time_ms = router.time_ms()
event.event_code = 1
event.event_flow_id = 2
infra_event = ChromeInfraEvent()
infra_event.cq_event.issue = str(i + 1)
event.source_extension = infra_event.SerializeToString()
events.append(event)
self.assertTrue(logger.push_event(events))
expected_calls = [
((logging.INFO,
'Sending event_mon event:\ncq_event {\n issue: "1"\n}\n'), ),
((logging.INFO,
'Sending event_mon event:\ncq_event {\n issue: "2"\n}\n'), ),
((logging.INFO,
'Sending event_mon event:\ncq_event {\n issue: "3"\n}\n'), )
]
self.assertEqual(log_mock.call_args_list, expected_calls)
def process_argparse_options(args):
"""Sets the default event based on --event-logrequest-path.
This function raises exceptions because if the base event is wrong, then it's
not worth sending anything anyway.
"""
event_mon.process_argparse_options(args)
_extra_argument_checking(args)
if args.event_logrequest_path:
try:
with open(args.event_logrequest_path, 'rb') as f:
request = LogRequestLite.FromString(f.read())
if len(request.log_event) == 1:
default_event = ChromeInfraEvent.FromString(
request.log_event[0].source_extension)
# Assume that the content is sane because we don't want to duplicate
# any business logic here.
# TODO(pgervais): find a better solution.
event_mon.set_default_event(default_event)
else:
raise ValueError(
'Expected only one log_event in the LogRequestLite proto '
'pointed by --event-logrequest-path. Found %d in %s',
len(request.log_event), args.event_logrequest_path)
except Exception:
LOGGER.exception('Failure when reading/parsing file %s',
args.event_logrequest_path)
raise
default_event = event_mon.get_default_event()
# When the default event is set using --event-logrequest-path, passing
# --build-event-type or --service-event-type is optional. These options
# still takes precedence but they must keep the event type the same.
if (default_event.build_event.HasField('type')
and default_event.service_event.HasField('type')):
msg = (
'Default event contains both service_event_type and '
'build_event_type which is incorrect. Make sure you passed '
'a correct proto to --event-logrequest-path. Otherwise it\'s an '
'internal error. Aborting.')
LOGGER.error(msg)
raise ValueError(msg)
if default_event.build_event.HasField('type'):
if args.service_event_type:
msg = (
'The default event contains a type for build_event, but a '
'service_event type was provided on the command-line. At most '
'one of them can be specified. Aborting.')
LOGGER.error(msg)
raise ValueError(msg)
if not args.build_event_type:
args.build_event_type = event_mon.BuildEvent.BuildEventType.Name(
default_event.build_event.type)
if default_event.service_event.HasField('type'):
if args.build_event_type:
msg = (
'The default event contains a type for service_event, but a '
'build_event type was provided on the command-line. At most '
'one of them can be specified. Aborting.')
LOGGER.error(msg)
raise ValueError(msg)
if not args.service_event_type:
args.service_event_type = event_mon.ServiceEvent.ServiceEventType.Name(
default_event.service_event.type)