They Say 20 Milliseconds, We Measure 300

Goal

You measure the same call from both the client and the server side and split the difference, bring connection pool wait inside the span boundary, record cut-off calls and canceled calls differently, design the target-identifying attributes as low-cardinality, and apply those rules as they are to a second client.

Why it matters

The downstream team's p99 and our p99 differ not because someone is wrong but because they measure different intervals. The server measures the time the handler was open, and before and after it there are queue time, serialization, and transmission. Worse is connection pool wait — if you start the span after getting the connection, that wait is in no span, and you end up with a trace where adding up all the children still does not explain the root. A timeout leaves the pair mismatched. Even if the client gives up, the server works to the end, so the same trace keeps a short CLIENT span and a long SERVER span together, and that shape is itself the sign that resources are leaking. Conversely, if you raise a cancellation caused by a user leaving to an error, the error rate swings with users' behavior. Finally, if you write the target of an outgoing call as the address itself, ids and Pod names get mixed into the attribute values and aggregation becomes impossible.

Steps

Create /root/tp-client/pair.py. Read the dump path from TRACELAB_OUT, and if it is absent it is /root/tp-client/pair.jsonl. The client service name is shop-api, and the downstream is Backend("pricing", <덤프와 같은 디렉터리>/server.jsonl) (the placeholder is the same directory as the dump). Inside the CLIENT span POST /price, inject the headers and call be.call("POST /price", 120, carrier), then write one line in pair.tsv in the same directory as the dump with <클라이언트 밀리초>, <서버 밀리초>, and <차이> separated by tabs (the placeholders are the client milliseconds, the server milliseconds, and the difference). To three decimal places.
Create /root/tp-client/gap.py and make the same call twenty times (the work is 30 milliseconds). The default dump path is /root/tp-client/gap.jsonl, and the server dump is gap-server.jsonl in the same directory. For each call, attach three attributes to the CLIENT span POST /price — gap.ms (client time minus server time), gap.queue_ms (the queue time the response reported), and gap.rest_ms (the difference between the two). Write twenty lines of <번호> and <gap.ms> in gap.tsv in the same directory as the dump (the placeholders are the item number and the gap.ms value), and in gap-summary.txt write median_gap_ms= (the median of the twenty values) and reason= (what the difference is made up of, in at least 100 characters).
Create /root/tp-client/pooled.py and do the same thing twice. The default dump path is /root/tp-client/pooled.jsonl, and the server dump is pooled-server.jsonl in the same directory. Both times, create a new ConnPool of size 1, and three threads call be.call("GET /stock", 80, carrier) at the same time. The first group opens the CLIENT span narrow after getting a slot from the pool, and the second group opens the CLIENT span wide first and then gets the slot, leaving the attribute pool.wait_ms and the event pool.acquired. In pool.tsv in the same directory as the dump, write two lines, narrow and wide, with the milliseconds of the span that was open longest in each group.
Create /root/tp-client/timeout.py. The default dump path is /root/tp-client/timeout.jsonl, and the server dump is timeout-server.jsonl in the same directory. Inside the CLIENT span GET /stock, call be.call("GET /stock", 400, carrier, timeout_ms=120), catch the timeout that is raised, set the span status to ERROR, and write timeout in the attribute error.type and 120 in rpc.timeout_ms. After waiting for the server job to finish with be.close(), flush(), then read the two dumps again, find the pair with the same trace_id, and write one line in orphan.tsv in the same directory as the dump with <trace_id>, <클라이언트 밀리초>, <서버 밀리초>, and <판정> separated by tabs (the placeholders are the trace_id, the client milliseconds, the server milliseconds, and the verdict). The verdict is client-gave-up if the server side is longer, and otherwise server-finished-first.
Create /root/tp-client/cancel.py and record two things. The default dump path is /root/tp-client/cancel.jsonl, and the server dump is cancel-server.jsonl in the same directory. (1) In the CLIENT span GET /recs, send the call with be.submit("GET /recs", 300, carrier), wait only 60 milliseconds, and then give up — do not touch the status, and leave the attribute rpc.cancelled set to true and an event rpc.cancelled. (2) In the CLIENT span GET /promo, call be.call("GET /promo", 20, carrier, fail=True), record the exception that is raised with record_exception, and then set the status to ERROR. In 05-cancel.txt in the same directory as the dump, write three lines, cancelled_status=, failed_status=, and reason= (why you record the two differently, in at least 100 characters).
Create /root/tp-client/target.py and send the eight cardinality calls from /opt/app/tracelab/tp_client/plan.json. The default dump path is /root/tp-client/target.jsonl, and the server dump is target-server.jsonl in the same directory. The CLIENT span name is <target>/<op> and you attach four attributes — rpc.service (target), rpc.method (op), server.address (target), and url.template (the path with only the order id replaced by the placeholder from plan.json). Do not put the address host or the order id in attribute values. In cardinality.tsv in the same directory as the dump, write four lines, tab-separated, with the name of each of the four attributes and the number of distinct values, in alphabetical order of attribute name.
Create /root/tp-client/repeat.py and send the seven checkout calls from /opt/app/tracelab/tp_client/plan.json under a single SERVER span POST /checkout. The default dump path is /root/tp-client/repeat.jsonl, and the server dump is repeat-server.jsonl in the same directory. On the root span, write the number of calls that went out in the attribute rpc.client.calls, and attach the same four attributes as in step 6 to each CLIENT span. In repeat.tsv in the same directory as the dump, write <server.address>, <rpc.method>, <호출 수>, and <걸린 시간 합(정수 밀리초)> separated by tabs (the placeholders are the address, the method, the number of calls, and the sum of the time taken in integer milliseconds), starting with the ones with the most calls. If the number of calls is the same, go in alphabetical order of address.
First write your judgments so far in /root/tp-client/client-policy.json — span_kind, boundary (whether pool wait is inside or outside the span), required_attributes (the four attributes from step 6), forbidden_value_sources (the field names in the material that must not be used as attribute values), timeout_status, and cancel_status. Then create /root/tp-client/second.py, read that file, and send the four search calls from /opt/app/tracelab/tp_client/plan.json as a second client. The default dump path is /root/tp-client/second.jsonl, the server dump is second-server.jsonl in the same directory, and you use a size-1 ConnPool and leave the time waited as pool.wait_ms inside the span. In second.tsv in the same directory as the dump, write three columns, <rpc.method>, <호출 수>, and <서로 다른 server.address 수> (the placeholders are the method, the number of calls, and the number of distinct server.address values), in alphabetical order of operation name.

Notes

The working directory is /root/tp-client. If it does not exist, create it first.
Always run the instrumented programs with /opt/otel-lab/bin/python. The system python3 does not have OpenTelemetry.
For the dump path, always read the environment variable TRACELAB_OUT first, and use the default path given in the task only when it is absent. Write the server dump and the table files in the same directory as the dump too — the grader runs the same program once more in its own temporary directory and compares.
The dump is appended to, so empty it at the start of the program with open(OUT, "w").close().
The materials are in /opt/app/tracelab/tp_client/ — backend.py (an imitation of a downstream service), pool.py (the connection pool), and plan.json (the list of outgoing calls). Read the first two files but do not edit them.
Common mistake: calling flush() without be.close(). If the worker thread is still running, the server span does not remain in the dump.
Common mistake: injecting the headers outside the CLIENT span. Then the server span does not become a child of that span.
Semantic Conventions — RPC spans · Trace API — span status · OpenTelemetry — span kind · OpenTelemetry Python — Instrumentation · Semantic Conventions — general attributes

Measure the same call from both sides

Create /root/tp-client/pair.py. Read the dump path from TRACELAB_OUT, and if it is absent it is /root/tp-client/pair.jsonl. The client service name is shop-api, and the downstream is Backend("pricing", <덤프와 같은 디렉터리>/server.jsonl) (the placeholder is the same directory as the dump). Inside the CLIENT span POST /price, inject the headers and call be.call("POST /price", 120, carrier), then write one line in pair.tsv in the same directory as the dump with <클라이언트 밀리초>, <서버 밀리초>, and <차이> separated by tabs (the placeholders are the client milliseconds, the server milliseconds, and the difference). To three decimal places.

server_ms in the dict that Backend.call returns is the time the server span was open. You can measure the client time by timing before and after the call with time.perf_counter(). You must inject the headers inside the span for the server span to become a child of this span. After calling be.close() at the end, flush().

What the difference is made up of

Create /root/tp-client/gap.py and make the same call twenty times (the work is 30 milliseconds). The default dump path is /root/tp-client/gap.jsonl, and the server dump is gap-server.jsonl in the same directory. For each call, attach three attributes to the CLIENT span POST /price — gap.ms (client time minus server time), gap.queue_ms (the queue time the response reported), and gap.rest_ms (the difference between the two). Write twenty lines of <번호> and <gap.ms> in gap.tsv in the same directory as the dump (the placeholders are the item number and the gap.ms value), and in gap-summary.txt write median_gap_ms= (the median of the twenty values) and reason= (what the difference is made up of, in at least 100 characters).

The response dict of Backend.call has queue_ms as well as server_ms — it is the time from the request arriving until the handler is picked up, and it is outside the server span. In a real service this value comes back in a response header. You can get the median by sorting the twenty values and averaging the middle two.

Bring the time waited in the connection pool inside the span

Create /root/tp-client/pooled.py and do the same thing twice. The default dump path is /root/tp-client/pooled.jsonl, and the server dump is pooled-server.jsonl in the same directory. Both times, create a new ConnPool of size 1, and three threads call be.call("GET /stock", 80, carrier) at the same time. The first group opens the CLIENT span narrow after getting a slot from the pool, and the second group opens the CLIENT span wide first and then gets the slot, leaving the attribute pool.wait_ms and the event pool.acquired. In pool.tsv in the same directory as the dump, write two lines, narrow and wide, with the milliseconds of the span that was open longest in each group.

ConnPool.lease() yields the milliseconds waited — with pool.lease() as waited:. The difference between the two groups is only the order of two lines of code, yet they look entirely different in a trace. If the two groups share the pool, the results get mixed, so create a new one for each group. Create threads with threading.Thread and join() them all.

Find the pair of a cut-off call in the dumps

Create /root/tp-client/timeout.py. The default dump path is /root/tp-client/timeout.jsonl, and the server dump is timeout-server.jsonl in the same directory. Inside the CLIENT span GET /stock, call be.call("GET /stock", 400, carrier, timeout_ms=120), catch the timeout that is raised, set the span status to ERROR, and write timeout in the attribute error.type and 120 in rpc.timeout_ms. After waiting for the server job to finish with be.close(), flush(), then read the two dumps again, find the pair with the same trace_id, and write one line in orphan.tsv in the same directory as the dump with <trace_id>, <클라이언트 밀리초>, <서버 밀리초>, and <판정> separated by tabs (the placeholders are the trace_id, the client milliseconds, the server milliseconds, and the verdict). The verdict is client-gave-up if the server side is longer, and otherwise server-finished-first.

The timeout of Backend.call is raised as concurrent.futures.TimeoutError. If you flush() without calling be.close(), the server span does not remain in the dump and you cannot find the pair. The dump is one JSON per line, so json.loads reads it as it is. The difference in length between the two spans is the point of this step.

Record a canceled call differently from an error

Create /root/tp-client/cancel.py and record two things. The default dump path is /root/tp-client/cancel.jsonl, and the server dump is cancel-server.jsonl in the same directory. (1) In the CLIENT span GET /recs, send the call with be.submit("GET /recs", 300, carrier), wait only 60 milliseconds, and then give up — do not touch the status, and leave the attribute rpc.cancelled set to true and an event rpc.cancelled. (2) In the CLIENT span GET /promo, call be.call("GET /promo", 20, carrier, fail=True), record the exception that is raised with record_exception, and then set the status to ERROR. In 05-cancel.txt in the same directory as the dump, write three lines, cancelled_status=, failed_status=, and reason= (why you record the two differently, in at least 100 characters).

A span whose status you did not touch remains as UNSET in the dump. Open the dump to confirm the two status values and then write them in the file — if you make them up, they will disagree with the dump. You catch the exception with from tracelab.tp_client.backend import BackendError.

Settle the target-identifying attributes as low-cardinality

Create /root/tp-client/target.py and send the eight cardinality calls from /opt/app/tracelab/tp_client/plan.json. The default dump path is /root/tp-client/target.jsonl, and the server dump is target-server.jsonl in the same directory. The CLIENT span name is <target>/<op> and you attach four attributes — rpc.service (target), rpc.method (op), server.address (target), and url.template (the path with only the order id replaced by the placeholder from plan.json). Do not put the address host or the order id in attribute values. In cardinality.tsv in the same directory as the dump, write four lines, tab-separated, with the name of each of the four attributes and the number of distinct values, in alphabetical order of attribute name.

limits in plan.json tells you how many values each attribute may have. host contains a Pod suffix and path contains an order id, so if you put them in as they are, the value differs on every call. There are two targets, so create one Backend per target and reuse it.

Expose, on the client side, that the same target was called several times

Create /root/tp-client/repeat.py and send the seven checkout calls from /opt/app/tracelab/tp_client/plan.json under a single SERVER span POST /checkout. The default dump path is /root/tp-client/repeat.jsonl, and the server dump is repeat-server.jsonl in the same directory. On the root span, write the number of calls that went out in the attribute rpc.client.calls, and attach the same four attributes as in step 6 to each CLIENT span. In repeat.tsv in the same directory as the dump, write <server.address>, <rpc.method>, <호출 수>, and <걸린 시간 합(정수 밀리초)> separated by tabs (the placeholders are the address, the method, the number of calls, and the sum of the time taken in integer milliseconds), starting with the ones with the most calls. If the number of calls is the same, go in alphabetical order of address.

There are two grouping keys, the target and the operation — which is why you needed low-cardinality attributes. If you write the number of calls on a single root span, you can filter out requests with a wide fan-out without unfolding the children. The time sum is the intervals wrapping each CLIENT call added up and rounded to an integer.

Write the rules in a file and apply them to a second client

First write your judgments so far in /root/tp-client/client-policy.json — span_kind, boundary (whether pool wait is inside or outside the span), required_attributes (the four attributes from step 6), forbidden_value_sources (the field names in the material that must not be used as attribute values), timeout_status, and cancel_status. Then create /root/tp-client/second.py, read that file, and send the four search calls from /opt/app/tracelab/tp_client/plan.json as a second client. The default dump path is /root/tp-client/second.jsonl, the server dump is second-server.jsonl in the same directory, and you use a size-1 ConnPool and leave the time waited as pool.wait_ms inside the span. In second.tsv in the same directory as the dump, write three columns, <rpc.method>, <호출 수>, and <서로 다른 server.address 수> (the placeholders are the method, the number of calls, and the number of distinct server.address values), in alphabetical order of operation name.

Do not write the attribute names out again in the program; attach them by looping over required_attributes in the rules file — that is what "apply the rules" means. In forbidden_value_sources, write the names of fields in plan.json that must not be used as they are. The two statuses are the values you confirmed from the dumps in steps 4 and 5.