def task_prerun_callback(task=None, **kwargs):
tracked_request = TrackedRequest.instance()
tracked_request.is_real_request = True
start = getattr(task.request, "scout_task_start", None)
if start is not None:
now = datetime_to_timestamp(dt.datetime.utcnow())
try:
queue_time = now - start
except TypeError:
pass
else:
tracked_request.tag("queue_time", queue_time)
task_id = getattr(task.request, "id", None)
if task_id:
tracked_request.tag("task_id", task_id)
parent_task_id = getattr(task.request, "parent_id", None)
if parent_task_id:
tracked_request.tag("parent_task_id", parent_task_id)
delivery_info = task.request.delivery_info
tracked_request.tag("is_eager", delivery_info.get("is_eager", False))
tracked_request.tag("exchange", delivery_info.get("exchange", "unknown"))
tracked_request.tag("routing_key", delivery_info.get("routing_key", "unknown"))
tracked_request.tag("queue", delivery_info.get("queue", "unknown"))
tracked_request.start_span(operation=("Job/" + task.name))
def track_request_queue_time(header_value, tracked_request):
if header_value.startswith("t="):
header_value = header_value[2:]
try:
first_char = header_value[0]
except IndexError:
return
if not first_char.isdigit(): # filter out negatives, nan, inf, etc.
return
try:
ambiguous_start_timestamp = float(header_value)
except ValueError:
return
start_timestamp_ns = convert_ambiguous_timestamp_to_ns(
ambiguous_start_timestamp)
if start_timestamp_ns == 0.0:
return
tr_start_timestamp_ns = datetime_to_timestamp(
tracked_request.start_time) * 1e9
# Ignore if in the future
if start_timestamp_ns > tr_start_timestamp_ns:
return
queue_time_ns = int(tr_start_timestamp_ns - start_timestamp_ns)
tracked_request.tag("scout.queue_time_ns", queue_time_ns)
def test_track_amazon_request_queue_time_valid(header_value, tracked_request):
start_time = int(datetime_to_timestamp(dt.datetime.utcnow())) - 2
result = track_amazon_request_queue_time(
header_value.format(start_time=start_time), tracked_request)
assert result is True
queue_time_ns = tracked_request.tags["scout.queue_time_ns"]
assert isinstance(queue_time_ns, int) and queue_time_ns > 0
def test_track_amazon_request_queue_time_valid(header_value, tracked_request):
start_time = int(datetime_to_timestamp(dt.datetime.utcnow())) - 2
result = track_amazon_request_queue_time(
header_value.format(start_time=start_time), tracked_request)
assert result is True
queue_time_ns = tracked_request.tags["scout.queue_time_ns"]
# Upper bound assumes we didn't take more than 2s to run this test...
assert queue_time_ns >= 2000000000 and queue_time_ns < 4000000000
def test_track_request_queue_time_valid(with_t, tracked_request):
queue_start = int(datetime_to_timestamp(dt.datetime.utcnow()) - 2)
if with_t:
header_value = str("t=") + str(queue_start)
else:
header_value = str(queue_start)
track_request_queue_time(header_value, tracked_request)
queue_time_ns = tracked_request.tags["scout.queue_time_ns"]
# Upper bound assumes we didn't take more than 2s to run this test...
assert queue_time_ns >= 2000000000 and queue_time_ns < 4000000000
def test_queue_time(header_name, tracked_requests):
# Not testing floats due to Python 2/3 rounding differences
queue_start = int(datetime_to_timestamp(dt.datetime.utcnow())) - 2
with app_with_scout() as app:
response = TestApp(app).get(
"/", headers={header_name: str("t=") + str(queue_start)})
assert response.status_int == 200
assert len(tracked_requests) == 1
queue_time_ns = tracked_requests[0].tags["scout.queue_time_ns"]
assert isinstance(queue_time_ns, int) and queue_time_ns > 0
def test_track_request_queue_time_valid(with_t, tracked_request):
queue_start = int(datetime_to_timestamp(dt.datetime.utcnow())) - 2
if with_t:
header_value = str("t=") + str(queue_start)
else:
header_value = str(queue_start)
result = track_request_queue_time(header_value, tracked_request)
assert result is True
queue_time_ns = tracked_request.tags["scout.queue_time_ns"]
assert isinstance(queue_time_ns, int) and queue_time_ns > 0
def test_queue_time(header_name, tracked_requests):
# Not testing floats due to Python 2/3 rounding differences
queue_start = int(datetime_to_timestamp(dt.datetime.utcnow()) - 2)
with app_with_scout() as app:
response = TestApp(app).get(
"/", headers={header_name: str("t=") + str(queue_start)})
assert response.status_int == 200
assert len(tracked_requests) == 1
queue_time_ns = tracked_requests[0].tags["scout.queue_time_ns"]
# Upper bound assumes we didn't take more than 2s to run this test...
assert queue_time_ns >= 2000000000 and queue_time_ns < 4000000000
def test_track_amazon_request_queue_time_hexidecimal_valid(
header_value, tracked_request):
start_time = format(
int(datetime_to_timestamp(dt.datetime.utcnow())) - 2, "x")
result = track_amazon_request_queue_time(
"Root=1-{start_time}-12456789abcdef012345678".format(
start_time=start_time),
tracked_request,
)
assert result is True
queue_time_ns = tracked_request.tags["scout.queue_time_ns"]
assert isinstance(queue_time_ns, int) and queue_time_ns > 0
def test_amazon_queue_time(tracked_requests):
queue_start = int(datetime_to_timestamp(dt.datetime.utcnow())) - 2
with app_with_scout() as app:
response = TestApp(app).get(
"/",
headers={
"X-Amzn-Trace-Id":
str("Self=1-{}-12456789abcdef012345678".format(queue_start))
},
)
assert response.status_int == 200
assert len(tracked_requests) == 1
queue_time_ns = tracked_requests[0].tags["scout.queue_time_ns"]
assert isinstance(queue_time_ns, int) and queue_time_ns > 0
def test_amazon_queue_time(tracked_requests):
queue_start = int(datetime_to_timestamp(dt.datetime.utcnow())) - 2
with app_with_scout() as app:
response = TestApp(app).get(
"/",
headers={
"X-Amzn-Trace-Id":
str("Self=1-{}-12456789abcdef012345678".format(queue_start))
},
)
assert response.status_int == 200
assert len(tracked_requests) == 1
queue_time_ns = tracked_requests[0].tags["scout.queue_time_ns"]
# Upper bound assumes we didn't take more than 2s to run this test...
assert queue_time_ns >= 2000000000 and queue_time_ns < 4000000000
async def test_queue_time(header_name, tracked_requests):
# Not testing floats due to Python 2/3 rounding differences
queue_start = int(datetime_to_timestamp(dt.datetime.utcnow())) - 2
with app_with_scout() as app:
communicator = ApplicationCommunicator(
app,
asgi_http_scope(
path="/", headers={header_name: str("t=") + str(queue_start)}),
)
await communicator.send_input({"type": "http.request"})
response_start = await communicator.receive_output()
await communicator.receive_output()
assert response_start["type"] == "http.response.start"
assert response_start["status"] == 200
queue_time_ns = tracked_requests[0].tags["scout.queue_time_ns"]
assert isinstance(queue_time_ns, int) and queue_time_ns > 0
def track_amazon_request_queue_time(header_value, tracked_request):
items = header_value.split(";")
found_item = None
for item in items:
if found_item is None and item.startswith("Root="):
found_item = item
elif item.startswith("Self="):
found_item = item
if found_item is None:
return False
pieces = found_item.split("-")
if len(pieces) != 3:
return False
timestamp_str = pieces[1]
try:
first_char = timestamp_str[0]
except IndexError:
return False
if not first_char.isdigit():
return False
# If the timestamp is 8 characters long, it's in hexadecimal format.
base = 16 if len(timestamp_str) == 8 else 10
try:
start_timestamp_ns = int(timestamp_str, base) * 1000000000.0
except ValueError:
return False
if start_timestamp_ns == 0:
return False
tr_start_timestamp_ns = datetime_to_timestamp(
tracked_request.start_time) * 1e9
# Ignore if in the futuren
if start_timestamp_ns > tr_start_timestamp_ns:
return False
queue_time_ns = int(tr_start_timestamp_ns - start_timestamp_ns)
tracked_request.tag("scout.queue_time_ns", queue_time_ns)
return True
async def test_queue_time(header_name, tracked_requests):
# Not testing floats due to Python 2/3 rounding differences
queue_start = int(datetime_to_timestamp(dt.datetime.utcnow())) - 2
with app_with_scout() as app:
communicator = ApplicationCommunicator(
app,
get_scope(path="/",
headers={header_name: str("t=") + str(queue_start)}),
)
await communicator.send_input({"type": "http.request"})
response_start = await communicator.receive_output()
await communicator.receive_output()
assert response_start["type"] == "http.response.start"
assert response_start["status"] == 200
queue_time_ns = tracked_requests[0].tags["scout.queue_time_ns"]
# Upper bound assumes we didn't take more than 2s to run this test...
assert queue_time_ns >= 2000000000 and queue_time_ns < 4000000000
async def test_amazon_queue_time(tracked_requests):
queue_start = int(datetime_to_timestamp(dt.datetime.utcnow())) - 2
with app_with_scout() as app:
communicator = ApplicationCommunicator(
app,
asgi_http_scope(
path="/",
headers={
"X-Amzn-Trace-Id":
"Self=1-{}-12456789abcdef012345678".format(queue_start)
},
),
)
await communicator.send_input({"type": "http.request"})
response_start = await communicator.receive_output()
await communicator.receive_output()
assert response_start["type"] == "http.response.start"
assert response_start["status"] == 200
queue_time_ns = tracked_requests[0].tags["scout.queue_time_ns"]
assert isinstance(queue_time_ns, int) and queue_time_ns > 0
async def test_amazon_queue_time(tracked_requests):
queue_start = int(datetime_to_timestamp(dt.datetime.utcnow())) - 2
with app_with_scout() as app:
communicator = ApplicationCommunicator(
app,
get_scope(
path="/",
headers={
"X-Amzn-Trace-Id":
"Self=1-{}-12456789abcdef012345678".format(queue_start)
},
),
)
await communicator.send_input({"type": "http.request"})
response_start = await communicator.receive_output()
await communicator.receive_output()
assert response_start["type"] == "http.response.start"
assert response_start["status"] == 200
queue_time_ns = tracked_requests[0].tags["scout.queue_time_ns"]
# Upper bound assumes we didn't take more than 2s to run this test...
assert queue_time_ns >= 2000000000 and queue_time_ns < 4000000000
"/", headers={header_name: str("t=") + str(queue_start)})
assert response.status_int == 200
assert len(tracked_requests) == 1
queue_time_ns = tracked_requests[0].tags["scout.queue_time_ns"]
# Upper bound assumes we didn't take more than 2s to run this test...
assert queue_time_ns >= 2000000000 and queue_time_ns < 4000000000
@pytest.mark.parametrize(
"header_value",
[
str(""),
str("t=X"), # first character not a digit
str("t=0.3f"), # raises ValueError on float() conversion
str(datetime_to_timestamp(dt.datetime.utcnow()) + 1000.0), # in future
str(datetime_to_timestamp(dt.datetime(2009, 1,
1))), # before ambig cutoff
],
)
def test_queue_time_invalid(header_value, tracked_requests):
with app_with_scout() as app:
response = TestApp(app).get("/",
headers={"X-Queue-Start": header_value})
assert response.status_int == 200
assert len(tracked_requests) == 1
assert "scout.queue_time_ns" not in tracked_requests[0].tags
def test_queue_time_future(tracked_requests):
def before_task_publish_callback(headers=None, properties=None, **kwargs):
if "scout_task_start" not in headers:
headers["scout_task_start"] = datetime_to_timestamp(dt.datetime.utcnow())
def test_datetime_to_timestamp(given, expected):
assert datetime_to_timestamp(given) == expected
result = track_request_queue_time(header_value, tracked_request)
assert result is True
queue_time_ns = tracked_request.tags["scout.queue_time_ns"]
# Upper bound assumes we didn't take more than 2s to run this test...
assert queue_time_ns >= 2000000000 and queue_time_ns < 4000000000
@pytest.mark.parametrize(
"header_value",
[
str(""),
str("t=X"), # first character not a digit
str("t=0.3f"), # raises ValueError on float() conversion
str(datetime_to_timestamp(dt.datetime.utcnow()) +
3600.0), # one hour in future
str(datetime_to_timestamp(dt.datetime(2009, 1,
1))), # before ambig cutoff
],
)
def test_track_request_queue_time_invalid(header_value, tracked_request):
result = track_request_queue_time(header_value, tracked_request)
assert result is False
assert "scout.queue_time_ns" not in tracked_request.tags
@pytest.mark.parametrize(
"header_value",
[
