Find the Slow Tool with Amazon Bedrock AgentCore Observability

Here is a real run of a small agent. Three tools, one question, correct answer:

tool call   : check_inventory({'sku': 'SKU-RED-01'})
tool call   : lookup_customer({'customer_id': 'C-1001'})
tool call   : estimate_delivery({'postcode': 'SW1A 1AA'})
answer : There are 42 units of SKU-RED-01 in stock, and the estimated
         delivery date for customer C-1001 is March 14, 2026.
took   : 6.2s

Six seconds is too slow. Now answer this: which part of it was slow?

You cannot, and neither can I, and the log above is the whole problem. It tells you three tools ran and the answer took six seconds. It does not tell you whether five of those seconds were one tool, or the model thinking between tools, or Bedrock being busy. Every debugging move from here is a guess.

This post is about closing that gap, and the whole change to the agent is smaller than you would expect.

What we're building

The same shape of agent as Part 1, with three tools instead of four:

• lookup_customer — find a customer by id
• check_inventory — how many units of a SKU are in stock
• estimate_delivery — an estimated delivery date

One of them is slow on purpose. Deploy it, look at a trace, and the answer stops being a guess and becomes a picture — roughly this shape, though your numbers will differ:

handle_invocation              4130 ms  ############################################
  lookup_customer                 3 ms  #
  check_inventory              1512 ms  ################
    inventory.sku = SKU-RED-01
  estimate_delivery               2 ms  #

Everything after this is how to get that picture, and the three things that will silently stop it appearing.

Logs, metrics and traces

These three words get used interchangeably and they are not the same thing.

A log is a line of text with a timestamp. Started. Called check_inventory. Done in 6.2s. Logs are excellent at telling you what happened and useless at telling you how long each part of it took, because each line knows only about itself.

A metric is a number over time. Average latency, invocations per minute, error rate. Metrics tell you something is wrong now — latency doubled at 14:05 — and nothing at all about which request or which line of code.

A trace is the one that answers our question. A trace follows a single request and records every step inside it as a span: a name, a start time, a duration, and a parent. Spans nest, so the picture you get is not a list — it is a tree with durations, and the long bar is your problem.

The vocabulary is worth learning properly because it is not AWS vocabulary. It is OpenTelemetry, an open standard, and the same words work in every language and every cloud.

AgentCore gives you spans for the invocation and the model calls without you writing anything. It cannot know which of your variables mattered — that part is yours, and it is three lines.

Where AgentCore fits

AgentCore Observability is not a new product you install. It is three pieces that already exist, wired together:

1. Your container runs under the ADOT (AWS Distro for OpenTelemetry) SDK, which collects spans.
2. AgentCore ships them to CloudWatch.
3. CloudWatch Transaction Search indexes them so the GenAI Observability console can draw the tree.

Each of the three has to be switched on, and each one fails silently when it is not. That is the real content of this post.

The agent

Nothing in agent.py mentions tracing:

# src/observable_agent/agent.py

def build_agent(settings: Settings | None = None) -> Agent:
    settings = settings or Settings.from_env()

    model = BedrockModel(
        model_id=settings.model_id,
        region_name=settings.region,
        temperature=0.2,
    )

    return Agent(
        model=model,
        system_prompt=SYSTEM_PROMPT,
        tools=[lookup_customer, check_inventory, estimate_delivery],
        callback_handler=None,
    )

That is Part 1's file with a different tool list. Strands emits OpenTelemetry spans for its model calls on its own; they get collected because of how the process starts, which we will come to.

The slow tool

# src/observable_agent/tools.py

INVENTORY_LATENCY_SECONDS = 1.5

tracer = trace.get_tracer("observable_agent.tools")


@tool
def check_inventory(sku: str) -> dict:
    """How many units of a SKU are in stock."""
    with tracer.start_as_current_span("check_inventory") as span:
        span.set_attribute("inventory.sku", sku)
        span.set_attribute("inventory.simulated_latency_s", INVENTORY_LATENCY_SECONDS)

        # Stands in for the slow warehouse API you actually have.
        time.sleep(INVENTORY_LATENCY_SECONDS)

        units = INVENTORY.get(sku.strip().upper())
        if units is None:
            span.set_attribute("inventory.found", False)
            return {"error": f"Unknown SKU {sku}"}

        span.set_attribute("inventory.found", True)
        span.set_attribute("inventory.units", units)
        return {"sku": sku, "units_in_stock": units}

Three things worth pausing on.

start_as_current_span makes it a child. Because it is current, any span opened inside it nests underneath automatically. That is how the tree in the picture builds itself — nobody passes a parent around.

The attributes are the point. A span that says check_inventory took 1512ms tells you where the time went. A span that also says inventory.sku = SKU-RED-01 tells you which lookup was slow, which is the difference between knowing you have a problem and being able to reproduce it.

Failures are recorded too. inventory.found = False means you can later ask "how often does this tool miss?" without adding a metric for it.

Testing that the instrumentation still exists

Instrumentation rots quietly. Somebody deletes a with tracer... line during a refactor, nothing fails, and you lose the data — usually discovering this during the next incident.

OpenTelemetry ships an in-memory exporter for exactly this:

# tests/test_tools.py

def test_the_slow_tool_records_why_it_is_slow(exporter):
    exporter.clear()
    check_inventory("SKU-RED-01")

    span = next(s for s in exporter.get_finished_spans() if s.name == "check_inventory")
    assert span.attributes["inventory.sku"] == "SKU-RED-01"
    assert span.attributes["inventory.units"] == 42

No AWS, no collector, no network. If someone removes the instrumentation, the test fails instead of the next incident.

The four things that switch tracing on

This is the part that costs people an afternoon. All four are required, none of them announce themselves, and three of them are outside your agent code.

1. The ADOT SDK, version 0.18.0 or later

dependencies = [
    "bedrock-agentcore>=1.21.0",
    "strands-agents>=1.51.0",
    "aws-opentelemetry-distro>=0.18.0",
    "boto3>=1.40.0",
]

Below 0.18.0 the per-agent span destination is ignored and your spans go to a shared log group instead of your agent's own. Everything appears to work; the spans are simply somewhere else.

2. Start the process under opentelemetry-instrument

CMD ["opentelemetry-instrument", "agent-serve"]

Not CMD ["agent-serve"]. This is the switch. opentelemetry-instrument is a wrapper that patches the libraries in your process — boto3, HTTP clients, threading — before your code imports them, then runs your entrypoint. There is no line of Python anywhere in this project that turns tracing on. It is turned on by how the process is launched.

3. Let the runtime deliver spans to its own log group

environment_variables = {
  BEDROCK_MODEL_ID                   = var.model_id
  UNIFIED_TRACES_DESTINATION_ENABLED = "true"
}

With this, logs, stdout and spans all land in /aws/bedrock-agentcore/runtimes/<id>-DEFAULT together. Without it they scatter, and correlating them becomes your problem.

The execution role also needs to be allowed to set that up:

statement {
  sid    = "SpanDeliveryResourcePolicy"
  effect = "Allow"
  actions = [
    "logs:PutResourcePolicy",
    "logs:DescribeResourcePolicies",
  ]
  resources = ["*"]
}

4. CloudWatch Transaction Search — account-wide

resource "aws_xray_trace_segment_destination" "cloudwatch_logs" {
  destination = "CloudWatchLogs"
}

This one is account-wide and region-wide, not per-agent. Leaving Terraform in charge of it means terraform destroy in this project switches it off for everything in that account and region. The project has a manage_transaction_search variable for that reason — set it to false if anything else depends on it, and enable it once by hand.

The switch Terraform cannot flip

There is a fifth thing, and it is the one that will actually get you.

As of AWS provider 6.58, aws_bedrockagentcore_agent_runtime has no tracing attribute. The per-agent Tracing toggle cannot be expressed in Terraform at all:

resource "aws_bedrockagentcore_agent_runtime" "agent" {
  agent_runtime_name = var.agent_name
  role_arn           = aws_iam_role.agent_execution.arn
  # ...
  # There is no `tracing` argument here. That is not an omission in this
  # example - the provider does not have one.
}

So after terraform apply, one manual step:

terraform output -raw enable_tracing_command

Or: AgentCore console → Agent Runtime → your agent → Tracing → Edit → Enable.

Skip it and everything looks perfectly configured, the deploy succeeds, the agent answers correctly — and no spans ever arrive. There is no error anywhere to tell you why.

Deploy it

The same three-step order as every other part of this series — the runtime cannot be created until an image exists:

cd terraform
terraform init
terraform apply -target=aws_ecr_repository.agent   # 1. repository

cd .. && ./scripts/build_and_push.sh v1            # 2. image (linux/arm64)

cd terraform && terraform apply                    # 3. everything else

Then the manual tracing toggle above, then invoke it:

uv run python scripts/invoke.py "How many SKU-RED-01 are left, and when would C-1001 get one?"

Reading the trace

The CloudWatch GenAI Observability console draws the tree for you: CloudWatch → GenAI Observability → your agent → a session → an invocation.

But a trace is not a console feature. It is structured log records in your agent's own log group, and you can read them with ordinary tools. That is what scripts/read_spans.py does — it pulls the spans stream and draws the waterfall as text:

uv run python scripts/read_spans.py

handle_invocation              4130 ms  ############################################
  lookup_customer                 3 ms  #
  check_inventory              1512 ms  ################
    inventory.sku = SKU-RED-01
    inventory.units = 42
  estimate_delivery               2 ms  #

(Your durations will differ — this shape is what to expect, not a promise about the numbers.)

Read it and the six-second mystery dissolves. check_inventory is 1.5 seconds and the other two tools are noise. And the interesting part is what is not accounted for: the tool spans add up to about 1.5 seconds inside a handle_invocation of about 4. The remaining seconds are the model — three round trips to Bedrock, one per tool call.

That changes what you would do next. Optimising check_inventory buys you 1.5 seconds at best. Getting the model to call the tools in one turn instead of three buys you more. You would not have known that from the logs, and the obvious guess — "the slow tool is the problem" — is the wrong one.

That is the whole argument for tracing in one paragraph.

When no spans arrive

In order of likelihood:

1. The per-agent Tracing toggle is off. Terraform cannot set it. This is the cause most of the time.
2. Transaction Search is off for the account.
3. The execution role is missing logs:PutResourcePolicy.
4. ADOT is older than 0.18.0, so the spans went to the shared aws/spans log group rather than your agent's.
5. The container does not start under opentelemetry-instrument.

read_spans.py prints this list when it finds nothing, because the failure mode is always the same: everything looks right and no data appears.

Cleaning up

cd terraform && terraform destroy

Remember that this also turns off Transaction Search account-wide unless you set manage_transaction_search = false.

What did we learn?

• Logs tell you it was slow. Traces tell you which part. A log line knows only about itself; a span knows its duration and its parent, so spans make a tree and the long bar is your answer.
• The vocabulary is OpenTelemetry, not AWS. Span, trace, attribute, exporter. The same words and the same SDK work anywhere.
• Tracing is switched on by how the process starts. opentelemetry-instrument in the Dockerfile, not a line of Python. Nothing in the agent mentions it.
• AgentCore traces the invocation; you trace the meaning. It cannot know that inventory.sku was the interesting variable. Three lines per tool, and a slow span becomes a reproducible one.
• Four switches, all silent. ADOT ≥ 0.18.0, opentelemetry-instrument, UNIFIED_TRACES_DESTINATION_ENABLED, and account-wide Transaction Search. Miss one and you get no error — just no data.
• The fifth switch is not in Terraform. Provider 6.58 has no tracing attribute on the runtime resource. One console click, or one CLI call, after every fresh deploy.
• Test your instrumentation. An InMemorySpanExporter and three assertions mean a deleted with tracer... line fails a test rather than an incident.
• Trust the trace over the guess. Here the slow tool was real and still not the biggest cost — the model's round trips were. That is the kind of thing you only find by measuring.