def pytest_sessionstart(session):
global apm_cli, apm_server_url, apm_token, apm_api_key, apm_service_name, apm_custom_context, \
apm_parent_id, apm_session_name, apm_labels
LOGGER.setLevel(logging.DEBUG)
config = session.config
apm_server_url = config.getoption("apm_server_url", default=None)
apm_token = config.getoption("apm_token", default=None)
apm_api_key = config.getoption("apm_api_key", default=None)
apm_service_name = config.getoption("apm_service_name", default=None)
apm_custom_context = config.getoption("apm_custom_context", default=None)
apm_session_name = config.getoption("apm_session_name")
apm_labels = json.loads(config.getoption("apm_labels"))
apm_cli = init_apm_client()
if apm_cli:
LOGGER.debug("Session transaction starts.")
elasticapm.instrument()
begin_transaction(apm_session_name)
elasticapm.label(**apm_labels)
set_context(apm_custom_context)
if apm_mode == 'dt':
with elasticapm.capture_span('Start session', labels=apm_labels):
apm_parent_id = get_parent_id()
# FIXME it is need to end the transaction to allow child transaction,
# if we do not end it the session transaction is not show in the UI.
end_transaction(apm_session_name)
def handle_complete(self):
while self.running:
result = self.complete_queue.pop(timeout=3)
if not result:
continue
cpu_mark = time.process_time()
time_mark = time.time()
# Start of ingest message
if self.apm_client:
self.apm_client.begin_transaction('ingest_msg')
sub = DatabaseSubmission(result)
self.completed(sub)
# End of ingest message (success)
if self.apm_client:
elasticapm.label(sid=sub.sid)
self.apm_client.end_transaction('ingest_complete', 'success')
self.counter.increment_execution_time(
'cpu_seconds',
time.process_time() - cpu_mark)
self.counter.increment_execution_time('busy_seconds',
time.time() - time_mark)
def handle_retries(self):
tasks = []
while self.sleep(0 if tasks else 3):
cpu_mark = time.process_time()
time_mark = time.time()
# Start of ingest message
if self.apm_client:
self.apm_client.begin_transaction('ingest_retries')
tasks = self.retry_queue.dequeue_range(upper_limit=isotime.now(),
num=100)
for task in tasks:
self.ingest_queue.push(task)
# End of ingest message (success)
if self.apm_client:
elasticapm.label(retries=len(tasks))
self.apm_client.end_transaction('ingest_retries', 'success')
self.counter.increment_execution_time(
'cpu_seconds',
time.process_time() - cpu_mark)
self.counter.increment_execution_time('busy_seconds',
time.time() - time_mark)
def update_stats():
if random.random() > 0.8:
dict_for_truncation = {k: k for k in range(500)}
assert False, "Bad luck!"
elasticapm.label(a="x", b="y")
elasticapm.set_custom_context({"a": "x", "b": "y"})
cache.set(utils.stats.cache_key, utils.stats(), 60)
def test_transaction_keyword_truncation(elasticapm_client):
too_long = "x" * (KEYWORD_MAX_LENGTH + 1)
expected = encoding.keyword_field(too_long)
assert too_long != expected
assert len(expected) == KEYWORD_MAX_LENGTH
assert expected[-1] != "x"
elasticapm_client.begin_transaction(too_long)
elasticapm.label(val=too_long)
elasticapm.set_user_context(username=too_long,
email=too_long,
user_id=too_long)
with elasticapm.capture_span(name=too_long, span_type=too_long):
pass
elasticapm_client.end_transaction(too_long, too_long)
elasticapm_client.close()
span = elasticapm_client.events["span"][0]
transaction = elasticapm_client.events["transaction"][0]
assert transaction["name"] == expected
assert transaction["type"] == expected
assert transaction["result"] == expected
assert transaction["context"]["user"]["id"] == expected
assert transaction["context"]["user"]["username"] == expected
assert transaction["context"]["user"]["email"] == expected
assert transaction["context"]["tags"]["val"] == expected
assert span["type"] == expected
assert span["name"] == expected
def get_last_reporting_ts(self, p_start_ts):
# Start of transaction
if self.apm_client:
self.apm_client.begin_transaction("Get last reporting timestamp")
self.log.info(
"Finding reporting timestamp for the last alert since {start_ts}..."
.format(start_ts=p_start_ts))
result = None
while result is None:
try:
result = self.datastore.alert.search(
f"reporting_ts:[{p_start_ts} TO *]",
sort='reporting_ts desc',
rows=1,
fl='reporting_ts',
as_obj=False)
except SearchException as e:
self.log.warning(
f"Failed to load last reported alert from the datastore, retrying... :: {e}"
)
continue
items = result.get('items', [{}]) or [{}]
ret_val = items[0].get("reporting_ts", p_start_ts)
# End of transaction
if self.apm_client:
elasticapm.label(start_ts=p_start_ts, reporting_ts=ret_val)
self.apm_client.end_transaction(
'get_last_reporting_ts',
'new_ts' if ret_val != p_start_ts else 'same_ts')
return ret_val
def post_order(request):
data = json.loads(request.body)
if 'customer_id' not in data:
return HttpResponse(status=400)
customer_obj = get_object_or_404(m.Customer, pk=data['customer_id'])
order_obj = m.Order.objects.create(customer=customer_obj)
total_amount = 0
for line in data['lines']:
product_obj = get_object_or_404(m.Product, pk=line['id'])
m.OrderLine.objects.create(order=order_obj,
product=product_obj,
amount=line['amount'])
total_amount += line['amount'] * product_obj.selling_price
# store lines count in and total amount in tags
label(
lines_count=len(data['lines']),
total_amount=total_amount / 100.0,
)
# store customer in transaction custom data
elasticapm.set_custom_context({
'customer_name': customer_obj.full_name,
'customer_email': customer_obj.email,
})
return JsonResponse({'id': order_obj.pk})
def ignore_cat(
self,
user_id,
cat_id,
):
apm_client.begin_transaction(transaction_type='http_request')
elasticapm.label(user_id=user_id)
try:
cats_collection.update_one(
filter={
'id': user_id,
},
update={
'$addToSet': {
'ignore_list': cat_id,
},
},
)
finally:
apm_client.end_transaction(
name='CatsService - ignore_cat',
result='success',
)
def run_archive_once(self):
reached_max = False
if not self.config.datastore.ilm.enabled:
return reached_max
now = now_as_iso()
# Archive data
for collection in self.archiveable_collections:
# Call heartbeat pre-dated by 5 minutes. If a collection takes more than
# 5 minutes to expire, this container could be seen as unhealthy. The down
# side is if it is stuck on something it will be more than 5 minutes before
# the container is restarted.
self.heartbeat(int(time.time() + 5 * 60))
# Start of expiry transaction
if self.apm_client:
self.apm_client.begin_transaction("Archive older documents")
archive_query = f"archive_ts:[* TO {now}]"
sort = ["archive_ts asc", "id asc"]
number_to_archive = collection.search(
archive_query,
rows=0,
as_obj=False,
use_archive=False,
sort=sort,
track_total_hits=ARCHIVE_SIZE)['total']
if number_to_archive == ARCHIVE_SIZE:
reached_max = True
if self.apm_client:
elasticapm.label(query=archive_query)
elasticapm.label(number_to_archive=number_to_archive)
self.log.info(f"Processing collection: {collection.name}")
if number_to_archive != 0:
# Proceed with archiving
if collection.archive(archive_query,
max_docs=number_to_archive,
sort=sort):
self.counter_archive.increment(
f'{collection.name}', increment_by=number_to_archive)
self.log.info(
f" Archived {number_to_archive} documents...")
else:
self.log.warning(
f" Failed to properly archive {number_to_archive} documents..."
)
else:
self.log.debug(" Nothing to archive in this collection.")
# End of expiry transaction
if self.apm_client:
self.apm_client.end_transaction(collection.name, 'archived')
return reached_max
def ListRecommendations(self, request, context):
# manually populate service map
# this can be removed once 7.8 is out and the python agent adds this by itself
product_catalog_destination_info = {
"address": os.environ.get('PRODUCT_CATALOG_SERVICE_ADDR', ''),
"port": int(os.environ.get('PORT', 8080)),
"service": {
"name": "grpc",
"resource": os.environ.get('PRODUCT_CATALOG_SERVICE_ADDR', ''),
"type": "external"
},
}
trace_parent = self.extract_trace_parent(context)
transaction = client.begin_transaction('request',
trace_parent=trace_parent)
request_dict = MessageToDict(request)
elasticapm.label(**{'request': request_dict})
max_responses = 5
# fetch list of products from product catalog stub
list_product_req = demo_pb2.Empty()
with elasticapm.capture_span(
'/hipstershop.ProductCatalogService/ListProducts',
labels=MessageToDict(list_product_req),
extra={"destination":
product_catalog_destination_info}) as span:
trace_parent = transaction.trace_parent.copy_from(
span_id=span.id, trace_options=TracingOptions(recorded=True))
cat_response, call = product_catalog_stub.ListProducts.with_call(
list_product_req,
metadata=[(constants.TRACEPARENT_HEADER_NAME,
trace_parent.to_string())])
with elasticapm.capture_span('CalculateRecommendations',
span_subtype='grpc',
span_action='calculate') as span:
product_ids = [x.id for x in cat_response.products]
filtered_products = list(
set(product_ids) - set(request.product_ids))
num_products = len(filtered_products)
num_return = min(max_responses, num_products)
# sample list of indicies to return
indices = random.sample(range(num_products), num_return)
# fetch product ids from indices
prod_list = [filtered_products[i] for i in indices]
logger.info(
'[Recv ListRecommendations] product_ids={}'.format(prod_list),
extra=get_extra_logging_payload())
# build and return response
response = demo_pb2.ListRecommendationsResponse()
response.product_ids.extend(prod_list)
elasticapm.label(**{'response': MessageToDict(response)})
elasticapm.set_custom_context({
'request': request_dict,
'response': MessageToDict(response)
})
client.end_transaction(
'/hipstershop.RecommendationService/ListRecommendations',
'success')
return response
def test_labels_merge(elasticapm_client):
elasticapm_client.begin_transaction("test")
elasticapm.label(foo=1, bar="baz")
elasticapm.label(bar=3, boo="biz")
elasticapm_client.end_transaction("test", "OK")
transactions = elasticapm_client.events[TRANSACTION]
assert transactions[0]["context"]["tags"] == {"foo": 1, "bar": 3, "boo": "biz"}
def SendEmail(self, request, context, send_mail=True):
trace_parent = None
for key, value in context.invocation_metadata():
if key.lower() == TRACEPARENT_HEADER_NAME:
trace_parent = TraceParent.from_string(value)
tx = client.begin_transaction('request', trace_parent=trace_parent)
tx.ensure_parent_id()
request_dict = MessageToDict(request)
elasticapm.label(**{'request': request_dict})
elasticapm.set_custom_context({
'request':
request_dict,
'response':
MessageToDict(demo_pb2.Empty())
})
email = request.email
order = request.order
parent_id = trace_parent.span_id
span = tx._begin_span('template.render',
None,
parent_span_id=parent_id)
try:
confirmation = template.render(order=order)
span.end()
except TemplateError as err:
client.capture_exception(context=request_dict, handled=True)
context.set_details(
'An error occurred when preparing the confirmation mail.')
logger.error(err.message, extra=default_fields)
context.set_code(grpc.StatusCode.INTERNAL)
span.end()
client.end_transaction(
'/hipstershop.EmailService/SendOrderConfirmation', 'failure')
return demo_pb2.Empty()
span = tx._begin_span('send_email', None, parent_span_id=parent_id)
try:
self.send_email(email, confirmation, send_mail)
span.end()
except EmailSendException as err:
client.capture_exception(context=request_dict, handled=True)
context.set_details('An error occurred when sending the email.')
logger.error('Failed to send email to %s' % email,
extra=get_extra_logging_payload())
logger.error(err.message, extra=get_extra_logging_payload())
context.set_code(grpc.StatusCode.INTERNAL)
span.end()
client.end_transaction(
'/hipstershop.EmailService/SendOrderConfirmation', 'failure')
return demo_pb2.Empty()
elasticapm.label(**{'response': MessageToDict(demo_pb2.Empty())})
client.end_transaction(
'/hipstershop.EmailService/SendOrderConfirmation', 'success')
return demo_pb2.Empty()
def stats(request):
from_cache = True
data = cache.get(utils.stats.cache_key)
if not data:
data = utils.stats()
cache.set(utils.stats.cache_key, data, 60)
from_cache = False
label(served_from_cache=from_cache)
return JsonResponse(data, safe=False)
def test_label_transaction():
requests_store = Tracer(lambda: [], lambda: [], lambda *args: None, Config(), None)
transaction = requests_store.begin_transaction("test")
elasticapm.label(foo="bar")
transaction.label(baz="bazzinga")
requests_store.end_transaction(200, "test")
assert transaction.labels == {"foo": "bar", "baz": "bazzinga"}
transaction_dict = transaction.to_dict()
assert transaction_dict["context"]["tags"] == {"foo": "bar", "baz": "bazzinga"}
def test_label_with_allowed_non_string_value():
requests_store = Tracer(lambda: [], lambda: [], lambda *args: None,
Config(), None)
t = requests_store.begin_transaction("test")
elasticapm.label(foo=1, bar=True, baz=1.1, bazzinga=decimal.Decimal("1.1"))
requests_store.end_transaction(200, "test")
assert t.labels == {
"foo": 1,
"bar": True,
"baz": 1.1,
"bazzinga": decimal.Decimal("1.1")
}
def test_label_with_not_allowed_non_string_value():
class SomeType(object):
def __str__(self):
return "ok"
def __unicode__(self):
return u"ok"
requests_store = Tracer(lambda: [], lambda: [], lambda *args: None, Config(), None)
t = requests_store.begin_transaction("test")
elasticapm.label(foo=SomeType())
requests_store.end_transaction(200, "test")
assert t.labels == {"foo": "ok"}
def handle_timeouts(self):
timeouts = []
while self.sleep(0 if timeouts else 3):
cpu_mark = time.process_time()
time_mark = time.time()
# Start of ingest message
if self.apm_client:
self.apm_client.begin_transaction('ingest_timeouts')
timeouts = self.timeout_queue.dequeue_range(
upper_limit=isotime.now(), num=100)
for scan_key in timeouts:
# noinspection PyBroadException
try:
actual_timeout = False
# Remove the entry from the hash of submissions in progress.
entry = self.scanning.pop(scan_key)
if entry:
actual_timeout = True
self.log.error("Submission timed out for %s: %s",
scan_key, str(entry))
dup = self.duplicate_queue.pop(_dup_prefix + scan_key,
blocking=False)
if dup:
actual_timeout = True
while dup:
self.log.error("Submission timed out for %s: %s",
scan_key, str(dup))
dup = self.duplicate_queue.pop(_dup_prefix + scan_key,
blocking=False)
if actual_timeout:
self.counter.increment('timed_out')
except Exception:
self.log.exception("Problem timing out %s:", scan_key)
# End of ingest message (success)
if self.apm_client:
elasticapm.label(timeouts=len(timeouts))
self.apm_client.end_transaction('ingest_timeouts', 'success')
self.counter.increment_execution_time(
'cpu_seconds',
time.process_time() - cpu_mark)
self.counter.increment_execution_time('busy_seconds',
time.time() - time_mark)
def get_cats(
self,
user_id,
):
apm_client.begin_transaction(transaction_type='http_request')
elasticapm.label(user_id=user_id)
try:
self.get_cats_for_user(user_id=user_id)
finally:
apm_client.end_transaction(
name='CatsService - get_cats',
result='success',
)
async def _instrument_request(request: Request):
if not self._client.should_ignore_url(url=request.path):
trace_parent = TraceParent.from_headers(headers=request.headers)
self._client.begin_transaction("request", trace_parent=trace_parent)
await set_context(
lambda: get_request_info(config=self._client.config, request=request),
"request",
)
self._setup_transaction_name(request=request)
if self._user_context_callback:
name, email, uid = await self._user_context_callback(request)
set_user_context(username=name, email=email, user_id=uid)
await self._setup_custom_context(request=request)
if self._label_info_callback:
labels = await self._label_info_callback(request)
label(**labels)
def post_order_csv(request):
customer_id = request.POST['customer']
customer_obj = get_object_or_404(m.Customer, pk=customer_id)
order_obj = m.Order.objects.create(customer=customer_obj)
total_amount = 0
i = 0
for i, line in enumerate(request.FILES['file']):
product_id, amount = map(int, line.decode('utf8').split(','))
product_obj = get_object_or_404(m.Product, pk=product_id)
m.OrderLine.objects.create(order=order_obj,
product=product_obj,
amount=amount)
total_amount += amount * product_obj.selling_price
label(
lines_count=i,
total_amount=total_amount / 100.0,
)
return HttpResponse('OK')
def test_transaction_context_is_used_in_errors(elasticapm_client):
elasticapm_client.begin_transaction("test")
elasticapm.label(foo="baz")
elasticapm.set_custom_context({"a": "b"})
elasticapm.set_user_context(username="******",
email="*****@*****.**",
user_id=42)
elasticapm_client.capture_message("x", custom={"foo": "bar"})
transaction = elasticapm_client.end_transaction("test", "OK")
message = elasticapm_client.events[ERROR][0]
assert message["context"]["custom"] == {"a": "b", "foo": "bar"}
assert message["context"]["user"] == {
"username": "******",
"email": "*****@*****.**",
"id": 42
}
assert message["context"]["tags"] == {"foo": "baz"}
assert "a" in transaction.context["custom"]
assert "foo" not in transaction.context["custom"]
def til_atom(
request_id,
user_id,
tts,
):
# Starting a transaction - passing the transaction type as an argument
apm_client.begin_transaction(transaction_type='tasks')
# Adding a label
elasticapm.label(request_id=request_id)
try:
# Do something very important
uranium_enrichment(tts=tts)
except Exception:
result = 'failure'
else:
result = 'success'
finally:
# Finishing the transaction - passing the transaction *name* and transaction result as an argument
apm_client.end_transaction(
name='til_atom',
result=result,
)
def test_labels_dedot(elasticapm_client):
elasticapm_client.begin_transaction("test")
elasticapm.label(**{"d.o.t": "dot"})
elasticapm.label(**{"s*t*a*r": "star"})
elasticapm.label(**{'q"u"o"t"e': "quote"})
elasticapm_client.end_transaction("test_name", 200)
transactions = elasticapm_client.events[TRANSACTION]
assert transactions[0]["context"]["tags"] == {"d_o_t": "dot", "s_t_a_r": "star", "q_u_o_t_e": "quote"}
def generate_distributed_traces(self, tasks_data, status, end_time,
traceparent, apm_service_name,
apm_server_url, apm_verify_server_cert,
apm_secret_token, apm_api_key):
""" generate distributed traces from the collected TaskData and HostData """
tasks = []
parent_start_time = None
for task_uuid, task in tasks_data.items():
if parent_start_time is None:
parent_start_time = task.start
tasks.append(task)
apm_cli = self.init_apm_client(apm_server_url, apm_service_name,
apm_verify_server_cert,
apm_secret_token, apm_api_key)
if apm_cli:
instrument() # Only call this once, as early as possible.
if traceparent:
parent = trace_parent_from_string(traceparent)
apm_cli.begin_transaction("Session",
trace_parent=parent,
start=parent_start_time)
else:
apm_cli.begin_transaction("Session", start=parent_start_time)
# Populate trace metadata attributes
if self.ansible_version is not None:
label(ansible_version=self.ansible_version)
label(ansible_session=self.session,
ansible_host_name=self.host,
ansible_host_user=self.user)
if self.ip_address is not None:
label(ansible_host_ip=self.ip_address)
for task_data in tasks:
for host_uuid, host_data in task_data.host_data.items():
self.create_span_data(apm_cli, task_data, host_data)
apm_cli.end_transaction(name=__name__,
result=status,
duration=end_time - parent_start_time)
def run_expiry_once(self):
now = now_as_iso()
reached_max = False
# Expire data
for collection in self.expirable_collections:
# Call heartbeat pre-dated by 5 minutes. If a collection takes more than
# 5 minutes to expire, this container could be seen as unhealthy. The down
# side is if it is stuck on something it will be more than 5 minutes before
# the container is restarted.
self.heartbeat(int(time.time() + 5 * 60))
# Start of expiry transaction
if self.apm_client:
self.apm_client.begin_transaction("Delete expired documents")
if self.config.core.expiry.batch_delete:
computed_date = epoch_to_iso(
dm(f"{now}||-{self.config.core.expiry.delay}h/d").
float_timestamp)
else:
computed_date = epoch_to_iso(
dm(f"{now}||-{self.config.core.expiry.delay}h").
float_timestamp)
delete_query = f"expiry_ts:[* TO {computed_date}]"
if self.config.core.expiry.delete_storage and collection.name in self.fs_hashmap:
file_delete = True
sort = ["expiry_ts asc", "id asc"]
else:
file_delete = False
sort = None
number_to_delete = collection.search(
delete_query,
rows=0,
as_obj=False,
use_archive=True,
sort=sort,
track_total_hits=EXPIRY_SIZE)['total']
if self.apm_client:
elasticapm.label(query=delete_query)
elasticapm.label(number_to_delete=number_to_delete)
self.log.info(f"Processing collection: {collection.name}")
if number_to_delete != 0:
if file_delete:
with elasticapm.capture_span(
name='FILESTORE [ThreadPoolExecutor] :: delete()',
labels={
"num_files": number_to_delete,
"query": delete_query
}):
# Delete associated files
with concurrent.futures.ThreadPoolExecutor(
self.config.core.expiry.workers,
thread_name_prefix="file_delete") as executor:
for item in collection.search(
delete_query,
fl='id',
rows=number_to_delete,
sort=sort,
use_archive=True,
as_obj=False)['items']:
executor.submit(
self.fs_hashmap[collection.name],
item['id'], computed_date)
self.log.info(
f' Deleted associated files from the '
f'{"cachestore" if "cache" in collection.name else "filestore"}...'
)
# Proceed with deletion
collection.delete_by_query(
delete_query,
workers=self.config.core.expiry.workers,
sort=sort,
max_docs=number_to_delete)
else:
# Proceed with deletion
collection.delete_by_query(
delete_query, workers=self.config.core.expiry.workers)
if number_to_delete == EXPIRY_SIZE:
reached_max = True
self.counter.increment(f'{collection.name}',
increment_by=number_to_delete)
self.log.info(
f" Deleted {number_to_delete} items from the datastore..."
)
else:
self.log.debug(" Nothing to delete in this collection.")
# End of expiry transaction
if self.apm_client:
self.apm_client.end_transaction(collection.name, 'deleted')
return reached_max
def label(self, **kwargs):
elasticapm.label(**kwargs)
def middleware(request):
__traceback_hide__ = True
if not request.user.is_authenticated:
request.user = random.choices(users, weights=weights)[0]
label(customer_tier=request.user.customer_tier)
return get_response(request)
def middleware(request):
__traceback_hide__ = True
label(request_id=str(uuid.uuid4()))
response = get_response(request)
return response
def test_label_while_no_transaction(caplog):
with caplog.at_level(logging.WARNING, "elasticapm.errors"):
elasticapm.label(foo="bar")
assert_any_record_contains(caplog.records, "foo", "elasticapm.errors")
def test_label_while_no_transaction(caplog):
with caplog.at_level(logging.WARNING, "elasticapm.errors"):
elasticapm.label(foo="bar")
record = caplog.records[0]
assert record.levelno == logging.WARNING
assert "foo" in record.args
