def test_run_hooks_and_send_adds_trace_fields(self):
''' ensure trace fields are propagated backwards '''
m_client = Mock()
tracer = SynchronousTracer(m_client)
tracer.start_trace()
m_span = Mock()
m_span.event = Event()
m_span.event.start_time = datetime.datetime.now()
# set an existing trace field
m_span.event.add_field('app.a', 1)
m_span.rollup_fields = defaultdict(float)
with patch('beeline.trace._should_sample') as m_sample_fn:
m_sample_fn.return_value = True
# add some trace fields
tracer.add_trace_field('a', 0)
tracer.add_trace_field('b', 2)
tracer.add_trace_field('c', 3)
tracer.finish_span(m_span)
# Check that the new, unique fields were successfully added
self.assertIn("app.b", m_span.event.fields())
self.assertIn("app.c", m_span.event.fields())
# Check that a was not overwritten with the new value of 0.
self.assertEqual(m_span.event.fields()["app.a"], 1)
def test_run_hooks_and_send_adds_trace_fields(self):
''' ensure trace fields are propagated backwards '''
m_client = Mock()
tracer = SynchronousTracer(m_client)
m_span = Mock()
m_span.event = Event()
m_span.event.start_time = datetime.datetime.now()
# set an existing trace field
m_span.event.add_field('app.a', 1)
m_span.rollup_fields = defaultdict(float)
with patch('beeline.trace._should_sample') as m_sample_fn:
m_sample_fn.return_value = True
# add some trace fields
tracer.add_trace_field('a', 0)
tracer.add_trace_field('b', 2)
tracer.add_trace_field('c', 3)
tracer.finish_span(m_span)
# ensure we only added fields b and c and did not try to overwrite a
self.assertDictContainsSubset({
'app.a': 1,
'app.b': 2,
'app.c': 3
}, m_span.event.fields())
def test_custom_dataset_propagates_to_event(self):
dataset = 'flibble'
m_client = Mock()
tracer = SynchronousTracer(m_client)
tracer._run_hooks_and_send = Mock()
span = tracer.start_trace(dataset=dataset)
event = m_client.new_event.return_value
tracer.finish_span(span)
self.assertEqual(event.dataset, dataset)
def test_add_rollup_field_propagates(self):
m_client = Mock()
tracer = SynchronousTracer(m_client)
tracer._run_hooks_and_send = Mock()
span1 = tracer.start_trace(context={'name': 'root'})
event1 = m_client.new_event.return_value
span2 = tracer.start_span(context={'name': 'middle'})
event2 = m_client.new_event.return_value
span3 = tracer.start_span(context={'name': 'inner1'})
event3 = m_client.new_event.return_value
tracer.add_rollup_field('database_ms', 17)
tracer.add_rollup_field('calories', 180)
tracer.add_rollup_field('database_ms', 23.1)
event3.add_field.reset_mock()
tracer.finish_span(span3)
event3.add_field.assert_has_calls([
call('database_ms', 17.0 + 23.1),
call('calories', 180.0),
call('duration_ms', ANY),
],
any_order=True)
span4 = tracer.start_span(context={'name': 'inner2'})
event4 = m_client.new_event.return_value
tracer.add_rollup_field('calories', 120)
event4.add_field.reset_mock()
tracer.finish_span(span4)
event4.add_field.assert_has_calls([
call('calories', 120.0),
call('duration_ms', ANY),
],
any_order=True)
event2.add_field.reset_mock()
tracer.finish_span(span2)
event2.add_field.assert_has_calls(
[
# This intermediate span doesn't get any rollup fields.
call('duration_ms', ANY),
],
any_order=True)
event1.add_field.reset_mock()
tracer.finish_span(span1)
event1.add_field.assert_has_calls([
call('rollup.database_ms', 17.0 + 23.1),
call('rollup.calories', 180.0 + 120.0),
call('duration_ms', ANY),
],
any_order=True)
def test_trace_context_manager_does_not_crash_if_span_is_none(self):
m_client = Mock()
tracer = SynchronousTracer(m_client)
tracer.start_span = Mock()
tracer.start_span.return_value = None
tracer.finish_span = Mock()
with tracer('foo'):
pass
tracer.start_span.assert_called_once_with(context={'name': 'foo'}, parent_id=None)
def test_trace_context_manager_starts_trace_if_trace_id_supplied(self):
''' ensure trace_id and parent_id get passed to start_trace if supplied '''
m_client = Mock()
tracer = SynchronousTracer(m_client)
tracer.start_trace = Mock()
mock_span = Mock()
tracer.start_trace.return_value = mock_span
tracer.finish_span = Mock()
with tracer('foo', trace_id='asdf', parent_id='zyxw'):
pass
tracer.start_trace.assert_called_once_with(context={'name': 'foo'}, trace_id='asdf', parent_span_id='zyxw')
tracer.finish_span.assert_called_once_with(mock_span)
def test_trace_context_manager_starts_span_if_trace_active(self):
m_client = Mock()
tracer = SynchronousTracer(m_client)
tracer.start_span = Mock()
tracer.start_trace = Mock()
tracer.get_active_trace_id = Mock(return_value='asdf')
mock_span = Mock()
tracer.start_span.return_value = mock_span
tracer.finish_span = Mock()
with tracer('foo') as span:
self.assertEqual(span, mock_span, 'tracer context manager should yield the span')
tracer.start_span.assert_called_once_with(context={'name': 'foo'}, parent_id=None)
tracer.start_trace.assert_not_called()
tracer.finish_span.assert_called_once_with(mock_span)
class Beeline(object):
def __init__(self,
writekey='', dataset='', service_name='',
tracer=None, sample_rate=1, api_host='https://api.honeycomb.io',
max_concurrent_batches=10, max_batch_size=100, send_frequency=0.25,
block_on_send=False, block_on_response=False,
transmission_impl=None, sampler_hook=None, presend_hook=None,
debug=False):
self.client = None
self.tracer_impl = None
self.presend_hook = None
self.sampler_hook = None
self.debug = debug
if debug:
self._init_logger()
# allow setting some values from the environment
if not writekey:
writekey = os.environ.get('HONEYCOMB_WRITEKEY', '')
if not dataset:
dataset = os.environ.get('HONEYCOMB_DATASET', '')
if not service_name:
service_name = os.environ.get('HONEYCOMB_SERVICE', dataset)
self.client = Client(
writekey=writekey, dataset=dataset, sample_rate=sample_rate,
api_host=api_host, max_concurrent_batches=max_concurrent_batches,
max_batch_size=max_batch_size, send_frequency=send_frequency,
block_on_send=block_on_send, block_on_response=block_on_response,
transmission_impl=transmission_impl,
user_agent_addition=USER_AGENT_ADDITION,
debug=debug,
)
self.log('initialized honeycomb client: writekey=%s dataset=%s service_name=%s',
writekey, dataset, service_name)
if not writekey:
self.log('writekey not set! set the writekey if you want to send data to honeycomb')
if not dataset:
self.log('dataset not set! set a value for dataset if you want to send data to honeycomb')
self.client.add_field('service_name', service_name)
self.client.add_field('meta.beeline_version', VERSION)
self.client.add_field('meta.local_hostname', socket.gethostname())
self.tracer_impl = SynchronousTracer(self.client)
self.tracer_impl.register_hooks(presend=presend_hook, sampler=sampler_hook)
self.sampler_hook = sampler_hook
self.presend_hook = presend_hook
def send_now(self, data):
''' DEPRECATED - to be removed in a future release
Create an event and enqueue it immediately. Does not work with
`beeline.add_field` - this is equivalent to calling `libhoney.send_now`
'''
ev = self.client.new_event()
if data:
ev.add(data)
self._run_hooks_and_send(ev)
def add_field(self, name, value):
''' Add a field to the currently active span.
`beeline.add_field("my field", "my value")`
If a field is being attributed to the wrong span/event,
make sure that `new_event` and `close_event` calls are matched.
'''
# fetch the current event from our tracer
span = self.tracer_impl.get_active_span()
# if there are no spans, this is a noop
if span is None:
return
span.add_context_field(name, value)
def add(self, data):
'''Similar to add_field(), but allows you to add a number of name:value pairs
to the currently active event at the same time.
`beeline.add({ "first_field": "a", "second_field": "b"})`
'''
# fetch the current event from the tracer
span = self.tracer_impl.get_active_span()
# if there are no spans, this is a noop
if span is None:
return
span.add_context(data)
def tracer(self, name, trace_id=None, parent_id=None):
return self.tracer_impl(name=name, trace_id=trace_id, parent_id=parent_id)
def new_event(self, data=None, trace_name=''):
''' DEPRECATED: Helper method that wraps `start_trace` and
`start_span`. It is better to use these methods as it provides
better control and context around how traces are implemented in your
app.
Creates a new span, populating it with the given data if
supplied. If no trace is running, a new trace will be started,
otherwise the event will be added as a span of the existing trace.
To send the event, call `beeline.send_event()`. There should be a
`send_event()` for each call to `new_event()`, or tracing and
`add` and `add_field` will not work correctly.
If trace_name is specified, will set the "name" field of the current span,
which is used in the trace visualizer.
'''
if trace_name:
data['name'] = trace_name
if self.tracer_impl.get_active_trace_id():
self.tracer_impl.start_span(context=data)
else:
self.tracer_impl.start_trace(context=data)
def send_event(self):
''' DEPRECATED: Sends the currently active event (current span),
if it exists.
There must be one call to `send_event` for each call to `new_event`.
'''
span = self.tracer_impl.get_active_span()
if span:
if span.is_root():
self.tracer_impl.finish_trace(span)
return
self.tracer_impl.finish_span(span)
def send_all(self):
''' send all spans in the trace stack, regardless of their
state
'''
span = self.tracer_impl.get_active_span()
while span:
if span.is_root():
self.tracer_impl.finish_trace(span)
return
self.tracer_impl.finish_span(span)
span = self.tracer_impl.get_active_span()
def traced(self, name, trace_id=None, parent_id=None):
def wrapped(fn, *args, **kwargs):
@functools.wraps(fn)
def inner(*args, **kwargs):
with self.tracer(name=name, trace_id=trace_id, parent_id=parent_id):
return fn(*args, **kwargs)
return inner
return wrapped
def traced_thread(self, fn):
trace_id = self.tracer_impl._state.trace_id
# copy as a new list - reference will be unavailable when we enter the new thread
stack = copy.copy(self.tracer_impl._state.stack)
trace_fields = copy.copy(self.tracer_impl._state.trace_fields)
@functools.wraps(fn)
def wrapped(*args, **kwargs):
self.tracer_impl._state.trace_id = trace_id
self.tracer_impl._state.stack = stack
self.tracer_impl._state.trace_fields = trace_fields
return fn(*args, **kwargs)
return wrapped
def _run_hooks_and_send(self, ev):
''' internal - run any defined hooks on the event and send '''
presampled = False
if self.sampler_hook:
self.log("executing sampler hook on event ev = %s", ev.fields())
keep, new_rate = self.sampler_hook(ev.fields())
if not keep:
self.log("skipping event due to sampler hook sampling ev = %s", ev.fields())
return
ev.sample_rate = new_rate
presampled = True
if self.presend_hook:
self.log("executing presend hook on event ev = %s", ev.fields())
self.presend_hook(ev.fields())
if presampled:
self.log("enqueuing presampled event ev = %s", ev.fields())
ev.send_presampled()
else:
self.log("enqueuing event ev = %s", ev.fields())
ev.send()
def _init_logger(self):
self._logger = logging.getLogger('honeycomb-beeline')
self._logger.setLevel(logging.DEBUG)
ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
ch.setFormatter(formatter)
self._logger.addHandler(ch)
def log(self, msg, *args, **kwargs):
if self.debug:
self._logger.debug(msg, *args, **kwargs)
def get_responses_queue(self):
return self.client.responses()
def close(self):
if self.client:
self.client.close()