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", [