--- title: 'Monitoring and Logging' source: 'https://academia.sh/en/courses/ai-agents/monitoring-and-logging' course: 'AI Agents' language: en updated: '2026-10-21T05:02:26+00:00' license: 'CC BY-SA 4.0' objectives: - 'Defines the three trace levels by the fields they store and counts the stored token at each.' - 'Computes the share of failed tasks whose cause can be found at each trace level.' - 'Measures the relation of the tool error counter to failure and separates the symptom from the cause.' - 'Shows that the ranking of the trace levels changes when the token is read per cause found.' --- # Monitoring and Logging Measuring what the step trace of an agent loop running in production reads back: in a 240-run stream made of ten runs of twenty-four tasks, fifteen tasks end wrong, and their causes are twelve wrong tool selections and three cases of wandering. The trace that stores only the result gives 0.0000 of these causes, the trace that counts tool names gives 0.4000, and the trace that stores the full observation gives 1.0000; the stored token rises from 2738 to 5954 and 13623, while the token per cause found falls from 992.3 to 908.2. 0.8689 of the sixty-one tool errors occur in runs that end correctly, that is, the tool error counter is a symptom, not a cause. The previous two lessons tested the agent. Tool-level testing probed, one by one, the defects placed in five tools; the end-to-end flow test caught what it missed, and a residual remained that neither could see. Both share one constraint: **we built the run being tested**. We knew in advance which task was running, which tool was broken, and what the correct answer was. In a loop running in production, none of these is at hand. The task comes from a subscriber, the agent chooses its own steps, the result is written to a record, and what remains is **only what we stored**. What this lesson measures is not the agent itself but **what the trace reads back**: when a task ends wrong, whether the record we stored can say **why** it ended wrong. The general procedure of observability was set up in the Observability and Reliability course and in the Observability and Operations course; it is not repeated here. The only thing measured is the trade-off between **the information the step trace carries and its cost**. - **AQ31.** The environment, tools, task set, and agent loop are **fictional** and are defined within the lesson below; no real model endpoint, tool server, or runtime is called. The seed is **20260218**, the second run **20260219**. - **AQ32. The production stream** is the same twenty-four tasks run **ten times**. Because the model is a nondeterministic component, the agent's draw is separate in each run; the total is **240 runs**. The step budget is **6**, that is, the value that came out best in the sweep of `agent-architecture/04`. - **AQ33. Three trace levels** store the following. **Result only**: the task name, the final answer, and whether the loop stopped. **Tool names**: in addition to these, how many times each tool was called — **the order is not stored**, because this level is a counter. **Full observation**: in addition to these, **the order of the calls and the whole of the observation each call returned**. - **AQ34. The cause** is the **first departure** in the trace and is read from the full observation: if a tool outside the plan was called before the plan finished, **wrong tool selection**; if calls continued after the plan finished, **wandering**; if a tool in the plan returned an error in its turn, **tool error**; if the plan did not finish with no departure at all, **budget**. - **AQ35.** A trace level gives a cause only **if the fields it stores determine it**; where it stays ambiguous, the cause counts as **not found**, and a wrong guess is not counted as right. - **AQ36.** The stored token is counted by passing the record through the shared tokenizer. The term used in this course for the trace is **step trace**. ## Production Stream and Shared Definition The block below sets up the shared definition of the course: the subscriber records of the measurement network, the fictional document set, five tools, twenty-four tasks, and the agent loop. Tool selection degrades with depth, the agent stops with a share of 0.88 when the work is done, fields outside the schema are filtered out, and a missing field is the tool's own error. The tool and field names in the code are the `read_meter`, `consumption`, `tariff`, `search_docs`, and `write_record` tools of the earlier lessons; they are counted in tokens here, so they stay Turkish. ```python # FICTIONAL. The measurement network's subscriber records, document set, five tools and # twenty-four tasks are defined within the lesson; no real endpoint or tool server is called. SEED, M32 = 20260218, 0xFFFFFFFF def rng(t): x = ((t ^ (t >> 16)) * 2246822507) & M32 x = ((x ^ (x >> 13)) * 3266489909) & M32 s = [(x ^ (x >> 16)) & M32] def next_value(): s[0] = (s[0] * 1664525 + 1013904223) & M32 return s[0] / 4294967296 return next_value def pick(u, w): t = 0.0 for i, x in enumerate(w): t += x if u < t: return i return len(w) - 1 def tokenize(m): b = [] for s in str(m).lower().replace(",", " , ").split(): while len(s) > 5: b.append(s[:5]) s = s[5:] b.append(s) return b def trace_id(m): h = 2166136261 for c in str(m): h = ((h ^ ord(c)) * 16777619) & M32 return h # wire words stay Turkish: they are counted in tokens (same rule as the MCP course) # onceki/simdiki/tip/bolge = previous/current/type/region; mesken/isyeri = residential/commercial REGION = ["dogu", "bati", "kuzey", "guney", "merkez"] TYPE = ["mesken", "isyeri"] SUBSCRIBERS = {} for i in range(60): r = rng(SEED + 31 * i) previous = 10000 + int(r() * 80000) SUBSCRIBERS[f"A{i + 1:03d}"] = {"bolge": REGION[int(r() * 5)], "tip": TYPE[int(r() * 2)], "onceki": previous, "simdiki": previous + int(r() * 70)} TIERS, ABOVE = ((10, 4), (25, 7), (40, 11)), 16 COMMERCIAL_FACTOR = 2 DOCUMENTS = {"TR01": "tarife basamaklari 10 25 40 metrekup ve ustu", "TR02": "isyeri abonesinde birim ucret iki katidir", "SY01": "endeks farki tuketimi verir sayac donusu 100000 eklenir", "AR01": "ariza kaydi acildiginda saha ekibi iki gun icinde gider", "KS01": "planli kesinti duyurusu bir hafta once yayimlanir"} CALLS = [0] # tool call counter def _charge(m3, type_): remaining, lower, total = m3, 0, 0 for upper, unit in TIERS: band = min(remaining, upper - lower) if band <= 0: break total += band * unit remaining -= band lower = upper total += remaining * ABOVE return total * (COMMERCIAL_FACTOR if type_ == "isyeri" else 1) def t_read_meter(abone=None, **_): a = SUBSCRIBERS.get(abone) if a is None: return {"hata": "abone yok"} return {"onceki": a["onceki"], "simdiki": a["simdiki"], "tip": a["tip"], "bolge": a["bolge"]} def t_consumption(onceki=None, simdiki=None, **_): if onceki is None or simdiki is None: return {"hata": "eksik alan"} f = simdiki - onceki return {"m3": f + 100000 if f < 0 else f} def t_tariff(m3=None, tip="mesken", **_): if m3 is None: return {"hata": "eksik alan"} return {"tutar": _charge(m3, tip)} def t_document(anahtar=None, **_): if not anahtar: return {"hata": "eksik alan"} q = set(tokenize(anahtar)) best, code = -1, None for k, m in DOCUMENTS.items(): o = len(q & set(tokenize(m))) if o > best: best, code = o, k return {"kod": code, "metin": DOCUMENTS[code]} if best > 0 else {"hata": "bulunamadi"} def t_record(abone=None, sutun=None, deger=None, **_): if not (abone and sutun and deger is not None): return {"hata": "eksik alan"} return {"yazildi": True, "abone": abone, "sutun": sutun, "deger": deger} TOOLS = { "sayac_oku": {"function": t_read_meter, "fields": ("abone",), "side_effect": False}, "tuketim": {"function": t_consumption, "fields": ("onceki", "simdiki"), "side_effect": False}, "tarife": {"function": t_tariff, "fields": ("m3", "tip"), "side_effect": False}, "belge_ara": {"function": t_document, "fields": ("anahtar",), "side_effect": False}, "kayit_yaz": {"function": t_record, "fields": ("abone", "sutun", "deger"), "side_effect": True}, } TOOL_NAMES = list(TOOLS) def call_tool(name, state): """Fields outside the schema are filtered out; a missing field is the tool's own error.""" CALLS[0] += 1 if name not in TOOLS: return {"hata": "arac yok"} kw = {a: state[a] for a in TOOLS[name]["fields"] if a in state} return TOOLS[name]["function"](**kw) TASKS = [] for i in range(24): r = rng(SEED + 9973 * i) sub = f"A{1 + int(r() * 60):03d}" t = pick(r(), [0.30, 0.22, 0.20, 0.28]) if t == 0: TASKS.append({"name": f"G{i + 1:02d}", "kind": "charge", "subscriber": sub, "request": f"{sub} abonesinin bu donem bedeli nedir", "sequence": ("sayac_oku", "tuketim", "tarife")}) elif t == 1: TASKS.append({"name": f"G{i + 1:02d}", "kind": "consumption", "subscriber": sub, "request": f"{sub} abonesinin bu donem tuketimi kac metrekup", "sequence": ("sayac_oku", "tuketim")}) elif t == 2: TASKS.append({"name": f"G{i + 1:02d}", "kind": "document", "subscriber": sub, "request": "sayac donusunde endeks farki nasil hesaplanir", "sequence": ("belge_ara",)}) else: TASKS.append({"name": f"G{i + 1:02d}", "kind": "record", "subscriber": sub, "request": f"{sub} abonesinin bedelini hesapla ve kayda yaz", "sequence": ("sayac_oku", "tuketim", "tarife", "kayit_yaz")}) def correct_answer(g): a = SUBSCRIBERS[g["subscriber"]] f = a["simdiki"] - a["onceki"] m3 = f + 100000 if f < 0 else f if g["kind"] == "consumption": return m3 if g["kind"] == "document": return "SY01" return _charge(m3, a["tip"]) def selection(d): return max(0.34, 0.80 - 0.09 * (d - 1)) # share of picking the right tool, falls with depth def agent(g, max_steps=8, seed=SEED, self_critique=False, approval=False): """FICTIONAL agent loop. No real model is called; tool selection comes from a single draw that depends on the task's sequence and the depth.""" r = rng(seed ^ trace_id(g["name"])) state = {"abone": g["subscriber"], "anahtar": g["request"], "sutun": "bedel"} trace, step, tok, errors = [], 0, 0, 0 seq, k = g["sequence"], 0 while step < max_steps: step += 1 tok += 60 + 22 * len(trace) target = seq[k] if k < len(seq) else None if target is None: # the job is done , the agent should stop if r() < 0.88: return {"done": True, "steps": step, "trace": trace, "tokens": tok, "errors": errors, "answer": state.get("sonuc"), "approvals": state.get("onay", 0)} choice = TOOL_NAMES[int(r() * len(TOOL_NAMES))] else: choice = target if r() < selection(k + 1) else TOOL_NAMES[int(r() * len(TOOL_NAMES))] if TOOLS[choice]["side_effect"] and approval: state["onay"] = state.get("onay", 0) + 1 if choice == "kayit_yaz": state["deger"] = state.get("sonuc") s = call_tool(choice, state) trace.append((choice, "hata" in s)) tok += 30 if "hata" in s: errors += 1 if self_critique: tok += 40 continue state.update({kk: vv for kk, vv in s.items() if kk != "hata"}) if choice == "tuketim": state["sonuc"] = s["m3"] if choice == "tarife": state["sonuc"] = s["tutar"] if choice == "belge_ara": state["sonuc"] = s["kod"] if choice == target: k += 1 return {"done": False, "steps": step, "trace": trace, "tokens": tok, "errors": errors, "answer": state.get("sonuc"), "approvals": state.get("onay", 0)} ``` ## What the Trace Reads Back The same flow runs for each of the three levels, the records are built, and the cause of the failed tasks is derived from the fields that level stored. To build the full observation level, the tool call is wrapped: the whole of the returned dictionary lands in the log. ```python # Production stream: the same task set runs ten times, and the agent's draw is separate in each run. BUDGET, RUNS = 6, 10 OBS_LOG = [] _raw_call = call_tool def call_tool(name, state): # full observation level: the returned fields are stored too s = _raw_call(name, state) OBS_LOG.append((name, dict(s))) return s def cause(g, trace): """Cause read from the full observation: the first departure in the trace.""" k = 0 for name, obs in trace: if k >= len(g["sequence"]): return "wandering" if name != g["sequence"][k]: return "wrong tool selection" if "hata" in obs: return "tool error" k += 1 return "budget" if k < len(g["sequence"]) else "unknown" def diagnose_names(g, counts): """The name level keeps only a counter: it has neither the order nor the observation.""" if not [a for a in counts if a not in g["sequence"]]: return None if [a for a in g["sequence"] if counts.get(a, 0) == 0]: return "wrong tool selection" if all(counts[a] == g["sequence"].count(a) for a in set(g["sequence"])): return "wandering" return None summary = {} for base_seed in (20260218, 20260219): found, stored, failed, distribution, errors, errors_correct = [0, 0, 0], [0, 0, 0], 0, {}, 0, 0 for d in range(RUNS): for g in TASKS: OBS_LOG.clear() s = agent(g, max_steps=BUDGET, seed=base_seed + 7 * d) trace = list(OBS_LOG) counts = {} for a, _ in trace: counts[a] = counts.get(a, 0) + 1 base_record = {"ad": g["name"], "yanit": s["answer"], "bitti": s["done"]} record = (base_record, dict(base_record, sayac=counts), dict(base_record, iz=trace)) for i in range(3): stored[i] += len(tokenize(record[i])) errors += s["errors"] if s["answer"] == correct_answer(g): errors_correct += s["errors"] continue failed += 1 actual = cause(g, trace) distribution[actual] = distribution.get(actual, 0) + 1 found[1] += diagnose_names(g, counts) == actual found[2] += cause(g, trace) == actual summary[base_seed] = (found, stored, failed) breakdown = " , ".join(f"{k} {v}" for k, v in sorted(distribution.items())) print(f"seed {base_seed} , {RUNS * len(TASKS)} runs , failed {failed} , cause: {breakdown}") print(f" tool errors {errors} , their share in runs that end correct {errors_correct / errors:.4f}") print("\ntrace level cause found share stored token per cause found") for i, name in enumerate(("result only", "tool names", "full observation")): a, b = summary[20260218], summary[20260219] share = f"{a[0][i] / a[2]:.4f} {b[0][i] / b[2]:.4f}" tok = f"{a[1][i]:>6} {b[1][i]:>6}" per = " ".join(f"{x[1][i] / x[0][i]:>7.1f}" if x[0][i] else " -" for x in (a, b)) print(f"{name:<18} {share} {tok} {per}") ``` ``` seed 20260218 , 240 runs , failed 15 , cause: wandering 3 , wrong tool selection 12 tool errors 61 , their share in runs that end correct 0.8689 seed 20260219 , 240 runs , failed 11 , cause: wandering 3 , wrong tool selection 8 tool errors 66 , their share in runs that end correct 0.9242 trace level cause found share stored token per cause found result only 0.0000 0.0000 2738 2739 - - tool names 0.4000 0.2727 5954 6043 992.3 2014.3 full observation 1.0000 1.0000 13623 14486 908.2 1316.9 ``` A trace that stores only the result gives **none** of the causes. This level can **count** failure: it knows that fifteen tasks ended wrong. When asked for the cause, all it has is the answer and the stop flag, and these two fields do not tell apart two separate paths that produce the same wrong answer. A dashboard can be built with this level; a fault cannot be closed with it. The trace that counts tool names gives **0.4000** of the causes. What this level knows is which tool was called how many times; there is no order. If an unplanned tool appears in the counter and **none** of the planned tools has been called, the plan is incomplete, that is, the departure is a wrong tool selection. If there is an unplanned tool but each of the planned tools has been called exactly once, the plan is finished and the extra call came afterward, that is, it is wandering. Outside these two cases the counter **cannot tell** two scenarios apart: the same counter can come from a wrong selection made in the middle of the plan and also from wandering after the plan finished. In those runs the cause counts as not found. The full observation level gives **all** of the causes, because the order is stored together with the observation each call returned, and the plan pointer can be replayed exactly. Its cost is that the stored token rises from 2738 to **13623** — five times. The last column changes the ranking. When read as **token per cause found**, the tool names level is 992.3 and the full observation level is **908.2**. The level that is five times more expensive in total is **cheaper** per unit of useful output, because most of the token the cheap level stores closes no question. In the second run the same reading is sharper still: 2014.3 against 1316.9. ## A Tool Error Is a Symptom, Not a Cause There are **61 tool errors** in the stream, and **0.8689 of them occur in runs that end correctly**. An alert placed on the tool error counter fires sixty-one times, and fifty-three of those are for a task that ended without trouble. It is deficient in the opposite direction too: the **tool error class never appears** in the table of causes. The mechanism explains this. When a tool in the plan has its turn, its input is already ready in the state and it returns no error; an error comes only when a **wrongly selected** tool cannot find the field its schema asks for. So a tool error always comes **after** a wrong selection, and looking at the error count without correcting that selection leads one to fix the tool. The two runs also draw the limit of this reading. The tool names level gives 0.4000 in one run and 0.2727 in the other; the difference of **0.1273** between them is the measurement band. That this level is **0.6000** behind the full observation is large relative to the band and is a finding. But how much this level's own value moved between the two runs says that a claim of the form "tool names give this much of the causes" is **unmeasured on its own**; what is measured is the order among the levels. ## Summary - The production stream is ten runs of twenty-four tasks; 15 of the 240 runs end wrong, and their causes are 12 wrong tool selections and 3 cases of wandering. - The result only level gives 0.0000 of the causes, the tool names level 0.4000, and the full observation level 1.0000. - The cost is 2738, 5954, and 13623 tokens; read per cause found, the ranking reverses and the full observation level drops to 908.2, below the 992.3 of tool names. - 0.8689 of the 61 tool errors are in runs that end correctly, and the tool error class never appears in the table of causes: the error counter is a symptom, not a cause. - The difference of the tool names level between the two runs is 0.1273; the value of this level on its own counts as unmeasured, and the order among the levels counts as measured. ## Next Step The trace reads back why a task ended wrong, and this has a token cost. But this cost is only one item of the bill the loop runs up. The agent makes one call at each step, every call spends tokens, and the number of steps changes from task to task. The next lesson reads this spending with two separate denominators: **per step** and **per correct answer**. There is a point where the two rankings are not the same, and at that point which setup counts as cheap depends on the choice of denominator.