def __exit__(self, exc, value, tb):
if not self.transaction:
return
if self.enter_time is not None:
exit_time = time.time()
start_time = self.enter_time
self.enter_time = None
trace_cache().record_event_loop_wait(start_time, exit_time)
global CancelledError
if CancelledError is None:
try:
from concurrent.futures import CancelledError
except:
CancelledError = GeneratorExit
# case: coroutine completed or cancelled
if (exc is StopIteration or exc is GeneratorExit
or exc is CancelledError):
self.transaction.__exit__(None, None, None)
# case: coroutine completed because of error
elif exc:
self.transaction.__exit__(exc, value, tb)
def wrap_finish(wrapped, instance, args, kwargs):
try:
return wrapped(*args, **kwargs)
finally:
transaction = getattr(instance, '_nr_transaction', None)
if transaction:
start_time = getattr(transaction, '_async_start_time', None)
if start_time:
trace_cache().record_event_loop_wait(start_time, time.time())
transaction._async_start_time = None
record_exception(*sys.exc_info(), ignore_errors=should_ignore)
transaction.__exit__(None, None, None)
instance._nr_transaction = None
def context_wrapper(wrapped, instance, args, kwargs):
cache = trace_cache()
thread_id = cache.thread_start(trace)
try:
return wrapped(*args, **kwargs)
finally:
cache.thread_stop(thread_id)
def collect_stack_traces(include_nr_threads=False, include_xrays=False):
"""Generator that yields the (thread category, stack trace) of all the
python threads.
"""
for (txn, thread_id, thread_category, frame) in \
trace_cache().active_threads():
# Skip NR Threads unless explicitly requested.
if (thread_category == 'AGENT') and (not include_nr_threads):
continue
stack_trace = format_stack_trace(frame, thread_category)
# Skip over empty stack traces. This is merely for optimization.
#
# It saves us from adding an empty deque to the txn obj, which will be
# discarded later on during call tree merge.
if not stack_trace:
continue
if include_xrays and txn:
txn.add_profile_sample(stack_trace)
yield thread_category, stack_trace
def test_context_propagation(event_loop, schedule, loop_policy):
import asyncio
asyncio.set_event_loop_policy(loop_policy)
exceptions = []
def handle_exception(loop, context):
exceptions.append(context)
event_loop.set_exception_handler(handle_exception)
schedule = getattr(asyncio, schedule, None) or getattr(
event_loop, schedule)
# Keep the trace around so that it's not removed from the trace cache
# through reference counting (for testing)
_ = event_loop.run_until_complete(_test(asyncio, schedule))
# The agent should have removed all traces from the cache since
# run_until_complete has terminated (all callbacks scheduled inside the
# task have run)
assert not trace_cache()._cache
# Assert that no exceptions have occurred
assert not exceptions, exceptions
def test_transaction_exit_trace_cache(fg):
"""
Verifying that the use of ensure_future will not cause errors
when traces remain in the trace cache after transaction exit
"""
import asyncio
exceptions = []
def handle_exception(loop, context):
exceptions.append(context)
async def bg(event):
with BackgroundTask(application(), 'bg'):
event.set()
async def handler():
task = await fg(asyncio, bg)
await task
def _test():
loop = asyncio.get_event_loop()
loop.set_exception_handler(handle_exception)
return loop.run_until_complete(handler())
_test()
# The agent should have removed all traces from the cache since
# run_until_complete has terminated
assert not trace_cache()._cache
# Assert that no exceptions have occurred
assert not exceptions, exceptions
def __init__(self, trace=None, request=None, trace_cache_id=None, strict=True):
self.trace = None
self.trace_cache = trace_cache()
self.thread_id = None
self.restore = None
self.should_restore = False
def log_propagation_failure(s):
if strict:
_logger.debug(
"Request context propagation failed. %s This may be an issue if there's an active transaction. Consult with New Relic support if further issues arise.",
s,
)
# Extract trace if possible, else leave as None for safety
if trace is None and request is None and trace_cache_id is None:
if strict:
log_propagation_failure("No trace or request provided.")
elif trace is not None:
self.trace = trace
elif trace_cache_id is not None:
self.trace = self.trace_cache._cache.get(trace_cache_id, None)
if self.trace is None:
log_propagation_failure("No trace with id %d." % trace_cache_id)
elif hasattr(request, "_nr_trace") and request._nr_trace is not None:
# Unpack traces from objects patched with them
self.trace = request._nr_trace
else:
log_propagation_failure("No context attached to request.")
def __enter__(self):
trace = getattr(self.request, "_nr_trace", None)
self.force_propagate = trace and current_trace() is None
# Propagate trace context onto the current task
if self.force_propagate:
self.thread_id = trace_cache().thread_start(trace)
def propagate_task_context(task):
trace = current_trace()
if trace:
cache = trace_cache()
cache._cache[id(task)] = trace
task.add_done_callback(remove_from_cache)
return task
def error_matches_rules(
rules_prefix,
exc_info,
status_code=None,
):
# Delay imports to prevent lockups
from newrelic.api.application import application_instance
from newrelic.core.trace_cache import trace_cache
trace = trace_cache().current_trace()
settings = trace and trace.settings
if not settings:
# Retrieve application settings
application = application_instance()
settings = application and application.settings
# Default to global settings
settings = settings or global_settings()
if not settings:
return False
# Retrieve settings based on prefix
classes_rules = getattr(settings.error_collector, "%s_classes" % rules_prefix, set())
status_codes_rules = getattr(settings.error_collector, "%s_status_codes" % rules_prefix, set())
module, name, fullnames, message = parse_exc_info(exc_info)
fullname = fullnames[0]
# Check class names
for fullname in fullnames:
if fullname in classes_rules:
return True
# Check status_code
# For callables, call on exc_info to retrieve status_code.
# It's possible to return None, in which case no code is evaluated.
if callable(status_code):
status_code = status_code(*exc_info)
# Match status_code if it exists
if status_code is not None:
try:
# Coerce into integer
status_code = int(status_code)
except:
_logger.error("Failed to coerce status code into integer. "
"status_code: %s" % str(status_code))
else:
if status_code in status_codes_rules:
return True
return False
def test_record_event_loop_wait_outside_task():
# Insert a random trace into the trace cache
trace = FunctionTrace(name="testing")
trace_cache()._cache[0] = trace
@background_task(name="test_record_event_loop_wait_outside_task")
def _test():
yield
for _ in _test():
pass
def __enter__(self):
# TODO 上下文管理协议，这个设计用的好。进入上下文前，把一些必要的事情先干了，比如设置起始时间；
# TODO 在离开上下文的时候，又干一些事情
self.parent = parent = self.parent or current_trace()
if not parent:
return self
# The parent may be exited if the stack is not consistent. This
# can occur when using ensure_future to schedule coroutines
# instead of using async/await keywords. In those cases, we
# must not trace.
#
# Don't do any tracing if parent is designated
# as a terminal node.
# 如果父节点已经退出或者是末位节点，就不进行任何追踪
if parent.exited or parent.terminal_node():
self.parent = None
return parent
transaction = parent.root.transaction
# Don't do further tracing of transaction if
# it has been explicitly stopped.
# 如果事务已经停止，不进行任何追踪
if transaction.stopped or not transaction.enabled:
self.parent = None
return self
parent.increment_child_count()
self.root = parent.root
self.should_record_segment_params = (
transaction.should_record_segment_params)
# Record start time.
self.start_time = time.time()
cache = trace_cache()
self.thread_id = cache.current_thread_id() # 获取当前追踪链路的线程id
# Push ourselves as the current node and store parent.
try:
cache.save_trace(self) # 将线程的追踪保存到缓存里
except:
self.parent = None
raise
self.activated = True
return self
def __enter__(self):
self.parent = parent = self.parent or current_trace()
if not parent:
return self
# The parent may be exited if the stack is not consistent. This
# can occur when using ensure_future to schedule coroutines
# instead of using async/await keywords. In those cases, we
# must not trace.
#
# Don't do any tracing if parent is designated
# as a terminal node.
if parent.exited or parent.terminal_node():
self.parent = None
return parent
transaction = parent.root.transaction
# Don't do further tracing of transaction if
# it has been explicitly stopped.
if transaction.stopped or not transaction.enabled:
self.parent = None
return self
parent.increment_child_count()
self.root = parent.root
self.should_record_segment_params = transaction.should_record_segment_params
# Record start time.
self.start_time = time.time()
cache = trace_cache()
self.thread_id = cache.current_thread_id()
# Push ourselves as the current node and store parent.
try:
cache.save_trace(self)
except:
self.parent = None
raise
self.activated = True
# Extract source code context
if self._source is not None:
self.add_code_level_metrics(self._source)
return self
def test_context_propagation(schedule, set_loop):
import asyncio
_loop = None
if set_loop:
class TestEventLoop(asyncio.SelectorEventLoop):
def create_task(self, coro, **kwargs):
return asyncio.tasks.Task(coro, loop=self, **kwargs)
_loop = asyncio.get_event_loop()
asyncio.set_event_loop(TestEventLoop())
loop = asyncio.get_event_loop()
exceptions = []
def handle_exception(loop, context):
exceptions.append(context)
loop.set_exception_handler(handle_exception)
schedule = getattr(asyncio, schedule, None) or getattr(loop, schedule)
# Keep the trace around so that it's not removed from the trace cache
# through reference counting (for testing)
_ = loop.run_until_complete(_test(asyncio, schedule))
# The agent should have removed all traces from the cache since
# run_until_complete has terminated (all callbacks scheduled inside the
# task have run)
assert not trace_cache()._cache
# Assert that no exceptions have occurred
assert not exceptions, exceptions
if _loop:
asyncio.set_event_loop(_loop)
def __enter__(self):
# If no transaction attempt to create it if first time entering context
# manager.
if self.transaction_init:
current_trace = trace_cache().prepare_for_root()
current_transaction = current_trace and current_trace.transaction
# If the current transaction's Sentinel is exited we can ignore it.
if not current_transaction:
self.transaction = self.transaction_init(None)
else:
self.transaction = self.transaction_init(current_transaction)
# Set transaction_init to None so we only attempt to create a
# transaction the first time entering the context.
self.transaction_init = None
if not self.transaction:
return self
if not self.transaction._state:
self.transaction.__enter__()
self.enter_time = time.time()
return self
def __exit__(self, exc, value, tb):
trace_cache().record_event_loop_wait(self.enter_time, time.time())
def current_thread_id():
return trace_cache().current_thread_id()
def remove_from_cache(task):
cache = trace_cache()
cache.task_stop(task)
async def recorder(ready, wait):
ready.set()
await wait.wait()
trace_cache().record_event_loop_wait(0, 1)
def propagate_task_context(task):
trace_cache().task_start(task)
task.add_done_callback(remove_from_cache)
return task
def __exit__(self, exc, value, tb):
if not self.parent:
return
# Check for violation of context manager protocol where
# __exit__() is called before __enter__().
if not self.activated:
_logger.error(
'Runtime instrumentation error. The __exit__() '
'method of %r was called prior to __enter__() being '
'called. Report this issue to New Relic support.\n%s', self,
''.join(traceback.format_stack()[:-1]))
return
transaction = self.root.transaction
# If the transaction has gone out of scope (recorded), there's not much
# we can do at this point.
if not transaction:
return
# If recording of time for transaction has already been
# stopped, then that time has to be used.
if transaction.stopped:
self.end_time = transaction.end_time
else:
self.end_time = time.time()
# Ensure end time is greater. Should be unless the
# system clock has been updated.
if self.end_time < self.start_time:
self.end_time = self.start_time
# Calculate duration and exclusive time. Up till now the
# exclusive time value had been used to accumulate
# duration from child nodes as negative value, so just
# add duration to that to get our own exclusive time.
self.duration = self.end_time - self.start_time
self.exclusive += self.duration
if self.exclusive < 0:
self.exclusive = 0
self.exited = True
self.exc_data = (exc, value, tb)
# in all cases except async, the children will have exited
# so this will create the node
if self._ready_to_complete():
self._complete_trace()
else:
# Since we're exited we can't possibly schedule more children but
# we may have children still running if we're async
trace_cache().pop_current(self)
def current_trace():
return trace_cache().current_trace()
def _complete_trace(self):
# transaction already completed, this is an error
if self.parent is None:
_logger.error(
'Runtime instrumentation error. The transaction '
'already completed meaning a child called complete trace '
'after the trace had been finalized. Trace: %r \n%s', self,
''.join(traceback.format_stack()[:-1]))
return
parent = self.parent
# Check to see if we're async
if parent.exited or parent.has_async_children:
self.is_async = True
# Pop ourselves as current node. If deferred, we have previously exited
# and are being completed by a child trace.
trace_cache().pop_current(self)
# Wipe out parent reference so can't use object
# again. Retain reference as local variable for use in
# this call though.
self.parent = None
# Wipe out root reference as well
transaction = self.root.transaction
self.root = None
# wipe out exc data
exc_data = self.exc_data
self.exc_data = (None, None, None)
# Give chance for derived class to finalize any data in
# this object instance. The transaction is passed as a
# parameter since the transaction object on this instance
# will have been cleared above.
self.finalize_data(transaction, *exc_data)
exc_data = None
# Give chance for derived class to create a standin node
# object to be used in the transaction trace. If we get
# one then give chance for transaction object to do
# something with it, as well as our parent node.
node = self.create_node()
if node:
transaction._process_node(node)
parent.process_child(node)
# ----------------------------------------------------------------------
# SYNC | The parent will not have exited yet, so no node will be
# | created. This operation is a NOP.
# ----------------------------------------------------------------------
# Async | The parent may have exited already while the child was
# | running. If this trace is the last node that's running, this
# | complete_trace will create the parent node.
# ----------------------------------------------------------------------
parent.complete_trace()
def __exit__(self, exc, value, tb):
if self.transaction:
start_time = self.transaction._async_start_time
if start_time:
trace_cache().record_event_loop_wait(start_time, time.time())
def error_matches_rules(
rules_prefix,
exc_info,
status_code=None,
settings=None,
):
"""
Attempt to match exception to rules based on prefix.
rules_prefix is one of [ignore, expected]
exc_info is an exception tuple of (exc, val, tb)
status_code is an optional value or callable taking in exc_info that returns an int-like object
origin is either the current application or trace.
"""
# Delay imports to prevent lockups
from newrelic.core.trace_cache import trace_cache
if not settings:
# Pull from current transaction if no settings provided
tc = trace_cache()
transaction = tc.current_transaction()
settings = transaction and transaction.settings
if not settings:
# Pull from active trace if no settings on transaction
trace = tc.current_trace()
settings = trace and trace.settings
if not settings:
# Unable to find rules to match with
_logger.debug(
"Failed to retrieve exception rules: No settings supplied, or found on transaction or trace."
)
return None
# Retrieve settings based on prefix
classes_rules = getattr(settings.error_collector,
"%s_classes" % rules_prefix, set())
status_codes_rules = getattr(settings.error_collector,
"%s_status_codes" % rules_prefix, set())
_, _, fullnames, _ = parse_exc_info(exc_info)
fullname = fullnames[0]
# Check class names
for fullname in fullnames:
if fullname in classes_rules:
return True
# Check status_code
# For callables, call on exc_info to retrieve status_code.
# It's possible to return None, in which case no code is evaluated.
if callable(status_code):
status_code = status_code(*exc_info)
# Match status_code if it exists
if status_code is not None:
try:
# Coerce into integer
status_code = int(status_code)
except:
_logger.error(
"Failed to coerce status code into integer. status_code: %s" %
str(status_code))
else:
if status_code in status_codes_rules:
return True
return False
def __init__(self, trace_cache_id):
self.trace_cache = trace_cache()
self.trace = self.trace_cache._cache.get(trace_cache_id)
self.thread_id = None
self.restore = None
def __exit__(self, exc, value, tb):
# Remove any context from the current thread as it was force propagated above
if self.force_propagate:
trace_cache().thread_stop(self.thread_id)
def remove_from_cache(task):
cache = trace_cache()
cache._cache.pop(id(task), None)
a = inspect.getfullargspec(func)
return (a.args, a.varargs, a.varkw, a.defaults)
if hasattr(inspect, 'getfullargspec'):
_argspec = _argspec_py3
else:
_argspec = _argspec_py2
from newrelic.core.agent import agent_instance
from newrelic.core.config import global_settings, flatten_settings
from newrelic.api.transaction import Transaction
from newrelic.api.object_wrapper import ObjectWrapper
from newrelic.core.trace_cache import trace_cache
_trace_cache = trace_cache()
def shell_command(wrapped):
args, varargs, keywords, defaults = _argspec(wrapped)
parser = optparse.OptionParser()
for name in args[1:]:
parser.add_option('--%s' % name, dest=name)
@functools.wraps(wrapped)
def wrapper(self, line):
result = shlex.split(line)
(options, args) = parser.parse_args(result)
def main_wrap_wrapper(wrapped, instance, args, kwargs):
awaitable = wrapped(*args, **kwargs)
return context_wrapper_async(awaitable, trace_cache().current_thread_id())
