Issue Station
Sign In
Tools hereToolbox

litellm - ✅(Solved) Fix [Bug]: Spend logs show 0 duration for failed requests — start_time and end_time are identical [3 pull requests, 1 participants]

Official PRs (…)
ON THIS PAGE

Recommended Tools

×6

Utilities matched from this issue’s tags and category — try them while you read without losing context.

GitHub issue graph ai analysis

Paste a GitHub issue URL. We fetch that issue, discover linked issues from bodies/comments/timeline, collect linked pull requests, and produce a structured English report.

The report is written in English Markdown for sharing and archival.

Helpful · Quick feedback

Loading…
GitHub stats
BerriAI/litellm#24888•Fetched 2026-04-08 01:59:04
View on GitHub
Comments
0
Participants
1
Timeline
12
Reactions
0
Author
madhu19991madhu19991
Participants
madhu19991madhu19991
Timeline (top)
referenced ×8cross-referenced ×3closed ×1

Root Cause

In litellm/proxy/hooks/proxy_track_cost_callback.py, the async_post_call_failure_hook method sets both timestamps to datetime.now():

# Lines 117-118
start_time=datetime.now(),
end_time=datetime.now(),

These should instead use the actual request start time from request_data["litellm_logging_obj"].start_time and set end_time to datetime.now().

Fix Action

Fix

litellm_logging_obj = request_data.get("litellm_logging_obj")
actual_start_time = litellm_logging_obj.start_time if litellm_logging_obj else datetime.now()

await proxy_logging_obj.db_spend_update_writer.update_database(
    ...
    start_time=actual_start_time,
    end_time=datetime.now(),
    ...
)

PR fix notes

PR #24906: fix: use actual start_time for failed request spend logs

Description (problem / solution / changelog)

Relevant issues

Fixes #24888

Summary

async_post_call_failure_hook in proxy_track_cost_callback.py set both start_time and end_time to datetime.now() when logging failed requests to the spend database. This caused all failed requests (timeouts, auth errors, etc.) to show Duration: 0.000s in the UI, making it impossible to determine how long the request actually ran before failing.

The fix extracts the actual request start time from litellm_logging_obj.start_time (which is set when the request first arrives) and uses datetime.now() only for end_time.

Before: Failed requests show Start Time == End Time, duration 0. After: Failed requests show the real duration from request arrival to failure.

Pre-Submission checklist

  • I have Added testing — 1 new test verifying start_time comes from logging obj, not datetime.now()
  • My PR passes all unit tests — 13/13 tests pass in test_proxy_track_cost_callback.py
  • My PR's scope is as isolated as possible, it only solves 1 specific problem
  • I have requested a Greptile review

Type

🐛 Bug Fix

Changes

  • litellm/proxy/hooks/proxy_track_cost_callback.py — Extract start_time from litellm_logging_obj instead of calling datetime.now() for both timestamps
  • tests/test_litellm/proxy/hooks/test_proxy_track_cost_callback.py — New test test_async_post_call_failure_hook_uses_actual_start_time verifying duration > 0 for simulated 60s request

Changed files

  • litellm/proxy/hooks/proxy_track_cost_callback.py (modified, +9/-1)
  • tests/test_litellm/proxy/hooks/test_proxy_track_cost_callback.py (modified, +64/-0)

PR #24936: fix(proxy): use actual request start_time for failed spend logs

Description (problem / solution / changelog)

Relevant issues

Fixes #24888 — failed requests logging Duration: 0.000s because both start_time and end_time were set to datetime.now() at failure time.

Pre-Submission checklist

Please complete all items before asking a LiteLLM maintainer to review your PR

  • I have Added testing in the tests/test_litellm/ directory, Adding at least 1 test is a hard requirement - see details
  • My PR passes all unit tests on make test-unit
  • My PR's scope is as isolated as possible, it only solves 1 specific problem
  • I have requested a Greptile review by commenting @greptileai and received a Confidence Score of at least 4/5 before requesting a maintainer review

Delays in PR merge?

If you're seeing a delay in your PR being merged, ping the LiteLLM Team on Slack (#pr-review).

CI (LiteLLM team)

CI status guideline:

  • 50-55 passing tests: main is stable with minor issues.
  • 45-49 passing tests: acceptable but needs attention
  • <= 40 passing tests: unstable; be careful with your merges and assess the risk.

  • Branch creation CI run
    Link:

  • CI run for the last commit
    Link:

  • Merge / cherry-pick CI run
    Links:

Type

🐛 Bug Fix

✅ Test

Changes

Problem: async_post_call_failure_hook in litellm/proxy/hooks/proxy_track_cost_callback.py (lines 123–124) called datetime.now() for both start_time and end_time when writing the spend log for a failed request. Both timestamps end up identical, so every failed request shows Duration: 0.000s regardless of how long the request actually ran.

Fix: _litellm_logging_obj is already fetched earlier in the same method (for trace ID propagation). Use _litellm_logging_obj.start_time as actual_start_time, with a datetime.now() fallback when the logging object is absent, and pass actual_start_time as start_time to update_database.

Tests added in tests/test_litellm/proxy/hooks/test_proxy_track_cost_callback.py:

  • test_async_post_call_failure_hook_uses_actual_start_time — asserts start_time equals litellm_logging_obj.start_time and end_time > start_time
  • test_async_post_call_failure_hook_falls_back_start_time_when_no_logging_obj — asserts the fallback path (datetime.now()) works cleanly when no logging object is present

Changed files

  • litellm/proxy/hooks/proxy_track_cost_callback.py (modified, +6/-1)
  • tests/test_litellm/proxy/hooks/test_proxy_track_cost_callback.py (modified, +88/-0)

PR #25108: Litellm ishaan april1 (#25103)

Description (problem / solution / changelog)

  • fix(proxy): enforce upperbound key params on key/update and add custom_key_update hook

The /key/update endpoint did not enforce upperbound_key_generate_params, allowing users to bypass configured limits (tpm_limit, rpm_limit, max_budget, duration, budget_duration) by updating an existing key instead of generating a new one.

Extract the upperbound enforcement logic from _common_key_generation_helper() into a standalone _enforce_upperbound_key_params() function and call it from both the generate and update paths. For updates, None values are skipped (not filled with defaults) since they mean "don't change this field".

Also adds a custom_key_update config option and user_custom_key_update global, mirroring the existing custom_key_generate pattern, so custom key validation logic can fire during key updates as well.

  • fix(proxy): invoke custom_key_update hook in bulk update path

The user_custom_key_update hook was only called in update_key_fn (single key update) but not in _process_single_key_update (bulk update path), allowing custom validation to be bypassed via the /key/update/bulk endpoint. Mirror the hook invocation in both paths.

  • fix(proxy): pass UpdateKeyRequest to hook in bulk path, not BulkUpdateKeyRequestItem

Move the custom_key_update hook invocation to after UpdateKeyRequest is constructed so the hook receives the same type in both single and bulk update paths. Previously the bulk path passed BulkUpdateKeyRequestItem (5 fields only), which would cause AttributeError for hooks accessing fields like tpm_limit or models.

  • fix(bedrock): promote cache usage to message_delta for Claude Code (#24850)

Ensure Bedrock/Anthropic-compatible streaming exposes cache usage where Claude Code reads it by promoting message_stop usage onto message_delta and preserving usage fields in fake-streamed message_delta events.

Made-with: Cursor

  • fix(search): Support self-hosted Firecrawl response format in search transform (#24866)

The transform_search_response method only handled Firecrawl Cloud (v2) response format where data is a dict with web/news keys. Self-hosted Firecrawl (v1) returns data as a flat list of result objects, causing an AttributeError: 'list' object has no attribute 'get'.

Detect the response format by checking if data is a list (self-hosted) or dict (cloud) and handle both cases.

Cloud format: {"data": {"web": [...], "news": [...]}} Self-hosted: {"success": true, "data": [{"url": "...", "title": "...", ...}]}

  • feat: add environment and user tracking to prompt management (#24855)

  • feat: add environment and user tracking to prompt management

  • Add environment (development/staging/production) and created_by columns to LiteLLM_PromptTable
  • Update unique constraint to [prompt_id, version, environment]
  • All CRUD endpoints support environment filtering and user tracking
  • Redesigned prompt detail page with environment tabs and version history
  • UI: environment filter on list page, environment selector in editor
  • 8 new tests for environment and user tracking

  • fix: Black formatting and add environments to PromptInfoResponse TypeScript type

  • fix: address Greptile review findings

  • P1: delete_prompt scopes in-memory cleanup to environment when provided
  • P2: dotprompt_content parsed directly regardless of environment flag
  • P2: use distinct for environments query
  • P2: fix double-fetch on initial mount in prompt_info.tsx
  • fix: remove unsupported select kwarg from find_many
  • fix: address remaining Greptile review comments
  • Remove unused useCallback import (index.tsx)
  • Remove unused ENV_COLORS variable (prompt_info.tsx)
  • P1: in-memory fallback in get_prompt_versions now respects environment filter
  • P1: reset selectedEnv when promptId changes to avoid stale state
  • Cyclic imports are pre-existing pattern, not introduced by this PR
  • fix: scope patch_prompt to environment using primary key
  • Add environment query param to patch_prompt endpoint
  • Look up target row by composite key (prompt_id + version + environment)
  • Update by primary key (id) to target exactly one row
  • Fixes Greptile finding: patch with multiple environments no longer ambiguous
  • fix: use actual start_time for failed request spend logs (#24906)

async_post_call_failure_hook set both start_time and end_time to datetime.now(), making all failed requests show duration=0. Use the actual start_time from litellm_logging_obj instead, so spend logs reflect the real request duration on timeout and other failures.

Fixes #24888

  • feat(bedrock): add nova canvas image edit support (#24869)

  • feat(bedrock): add nova canvas image edit support

  • fix(bedrock): support PathLike inputs for nova image edit

  • chore: sync schema.prisma copies from root

  • fix(mypy): correct type-ignore code for delta_usage arg-type

  • fix(mypy): cast status_code to str, suppress intentional str yield

  • fix(lint): extract _create_content_block_chunks to fix PLR0915

  • fix(lint): extract helpers to fix PLR0915 in prompt endpoints

Relevant issues

<!-- e.g. "Fixes #000" -->

Pre-Submission checklist

Please complete all items before asking a LiteLLM maintainer to review your PR

  • I have Added testing in the tests/test_litellm/ directory, Adding at least 1 test is a hard requirement - see details
  • My PR passes all unit tests on make test-unit
  • My PR's scope is as isolated as possible, it only solves 1 specific problem
  • I have requested a Greptile review by commenting @greptileai and received a Confidence Score of at least 4/5 before requesting a maintainer review

Delays in PR merge?

If you're seeing a delay in your PR being merged, ping the LiteLLM Team on Slack (#pr-review).

CI (LiteLLM team)

CI status guideline:

  • 50-55 passing tests: main is stable with minor issues.
  • 45-49 passing tests: acceptable but needs attention
  • <= 40 passing tests: unstable; be careful with your merges and assess the risk.

  • Branch creation CI run
    Link:

  • CI run for the last commit
    Link:

  • Merge / cherry-pick CI run
    Links:

Type

<!-- Select the type of Pull Request --> <!-- Keep only the necessary ones -->

🆕 New Feature 🐛 Bug Fix 🧹 Refactoring 📖 Documentation 🚄 Infrastructure ✅ Test

Changes

Changed files

  • docs/my-website/docs/providers/bedrock_image_gen.md (modified, +23/-1)
  • litellm-proxy-extras/litellm_proxy_extras/migrations/20260331000000_add_prompt_environment_and_created_by/migration.sql (added, +12/-0)
  • litellm-proxy-extras/litellm_proxy_extras/schema.prisma (modified, +10/-6)
  • litellm/llms/anthropic/experimental_pass_through/messages/fake_stream_iterator.py (modified, +116/-138)
  • litellm/llms/bedrock/image_edit/amazon_nova_canvas_image_edit_transformation.py (added, +515/-0)
  • litellm/llms/bedrock/image_edit/handler.py (modified, +12/-2)
  • litellm/llms/bedrock/messages/invoke_transformations/anthropic_claude3_transformation.py (modified, +79/-1)
  • litellm/llms/firecrawl/search/transformation.py (modified, +51/-37)
  • litellm/model_prices_and_context_window_backup.json (modified, +9/-1)
  • litellm/proxy/guardrails/guardrail_hooks/model_armor/model_armor.py (modified, +2/-2)
  • litellm/proxy/hooks/proxy_track_cost_callback.py (modified, +9/-1)
  • litellm/proxy/management_endpoints/key_management_endpoints.py (modified, +92/-45)
  • litellm/proxy/prompts/prompt_endpoints.py (modified, +315/-132)
  • litellm/proxy/proxy_server.py (modified, +11/-3)
  • litellm/proxy/schema.prisma (modified, +4/-1)
  • litellm/types/prompts/init_prompts.py (modified, +6/-0)
  • litellm/utils.py (modified, +3/-3)
  • model_prices_and_context_window.json (modified, +9/-1)
  • schema.prisma (modified, +4/-1)
  • tests/test_litellm/llms/bedrock/image_edit/test_amazon_nova_canvas_image_edit.py (added, +657/-0)
  • tests/test_litellm/llms/bedrock/messages/invoke_transformations/test_anthropic_claude3_transformation.py (modified, +83/-23)
  • tests/test_litellm/proxy/guardrails/guardrail_hooks/test_model_armor.py (modified, +1/-1)
  • tests/test_litellm/proxy/hooks/test_proxy_track_cost_callback.py (modified, +64/-0)
  • tests/test_litellm/proxy/management_endpoints/test_key_management_endpoints.py (modified, +144/-0)
  • tests/test_litellm/proxy/prompts/test_prompt_environment.py (added, +253/-0)
  • tests/test_litellm/test_utils.py (modified, +1/-0)
  • ui/litellm-dashboard/src/components/networking.tsx (modified, +22/-6)
  • ui/litellm-dashboard/src/components/prompts.tsx (modified, +19/-6)
  • ui/litellm-dashboard/src/components/prompts/prompt_editor_view/PromptEditorHeader.tsx (modified, +16/-1)
  • ui/litellm-dashboard/src/components/prompts/prompt_editor_view/index.tsx (modified, +20/-1)
  • ui/litellm-dashboard/src/components/prompts/prompt_editor_view/types.ts (modified, +1/-0)
  • ui/litellm-dashboard/src/components/prompts/prompt_editor_view/utils.ts (modified, +1/-0)
  • ui/litellm-dashboard/src/components/prompts/prompt_info.tsx (modified, +225/-90)
  • ui/litellm-dashboard/src/components/prompts/prompt_table.tsx (modified, +30/-0)

Code Example

Start Time: 2026-03-31T16:28:24.191Z
End Time:   2026-03-31T16:28:24.191Z
Duration:   0.000 s

---

# Lines 117-118
start_time=datetime.now(),
end_time=datetime.now(),

---

litellm_logging_obj = request_data.get("litellm_logging_obj")
actual_start_time = litellm_logging_obj.start_time if litellm_logging_obj else datetime.now()

await proxy_logging_obj.db_spend_update_writer.update_database(
    ...
    start_time=actual_start_time,
    end_time=datetime.now(),
    ...
)
RAW_BUFFERClick to expand / collapse

Bug

When a request fails (e.g., timeout), the spend log records start_time and end_time as the same timestamp, resulting in Duration: 0.000s. Successful requests log the correct duration.

Example from a timeout failure:

Start Time: 2026-03-31T16:28:24.191Z
End Time:   2026-03-31T16:28:24.191Z
Duration:   0.000 s

The actual request ran for ~300 seconds before Akamai timed it out.

Root Cause

In litellm/proxy/hooks/proxy_track_cost_callback.py, the async_post_call_failure_hook method sets both timestamps to datetime.now():

# Lines 117-118
start_time=datetime.now(),
end_time=datetime.now(),

These should instead use the actual request start time from request_data["litellm_logging_obj"].start_time and set end_time to datetime.now().

Expected Behavior

Failed requests should show the actual duration from when the request was sent to when the failure was recorded, the same way successful requests do.

Fix

litellm_logging_obj = request_data.get("litellm_logging_obj")
actual_start_time = litellm_logging_obj.start_time if litellm_logging_obj else datetime.now()

await proxy_logging_obj.db_spend_update_writer.update_database(
    ...
    start_time=actual_start_time,
    end_time=datetime.now(),
    ...
)

Environment

  • LiteLLM version: 1.81.14
  • Observed on gsk-prod cluster with Azure gpt-4.1 timeout failures

extent analysis

TL;DR

Update the async_post_call_failure_hook method to use the actual request start time from request_data["litellm_logging_obj"].start_time and set end_time to datetime.now() to correctly log the duration of failed requests.

Guidance

  • Verify that request_data["litellm_logging_obj"] is not None before accessing its start_time attribute to avoid potential errors.
  • Update the async_post_call_failure_hook method as shown in the provided fix to correctly set start_time and end_time for failed requests.
  • Test the updated method with both successful and failed requests to ensure the duration is logged correctly in all cases.
  • Consider adding error handling for cases where request_data["litellm_logging_obj"] is None or its start_time attribute is not set.

Example

litellm_logging_obj = request_data.get("litellm_logging_obj")
actual_start_time = litellm_logging_obj.start_time if litellm_logging_obj else datetime.now()

await proxy_logging_obj.db_spend_update_writer.update_database(
    ...
    start_time=actual_start_time,
    end_time=datetime.now(),
    ...
)

Notes

This fix assumes that request_data["litellm_logging_obj"].start_time is set correctly for all requests. If this is not the case, additional debugging may be necessary to determine why the start time is not being set.

Recommendation

Apply the provided workaround by updating the async_post_call_failure_hook method to correctly set start_time and end_time for failed requests, as this will ensure accurate logging of request durations.

Vote matrix · Quick signals

Works
Did the solution work? Tap to confirm.
Easy Fix
Was it a quick fix?
Time Saver
Did it save you time?
Blocking
Was it severely blocking?
Common Issue
Are others likely hitting this too?
Flaky / Intermittent
Is it intermittent?
Verified / Reproducible
Can you reproduce it reliably?
Loading…
#database connection#vector store#embedding generation#cache error#pipeline error

Still need to ship something?

×6

Another batch ranked right after the header list — different links, same matching logic.

Back to top recommendations

TRENDING

litellm - ✅(Solved) Fix [Bug]: Spend logs show 0 duration for failed requests — start_time and end_time are identical [3 pull requests, 1 participants]