Skip to content

Access log entry for request duration is negative #2979

@dadrus

Description

@dadrus

Preflight checklist

  • I agree to follow this project's Code of Conduct.
  • I have read and am following this repository's Contribution Guidelines."
  • I could not find a solution in the existing issues, docs, nor discussions.

Describe the bug

The access log field _tx_duration_ms, which represents the request duration, is typically 0 because the time unit used is milliseconds. However, when heimdall performs outbound requests (depending on the executed rule) and the total duration exceeds one millisecond, the value of this field becomes negative.

How can the bug be reproduced

The issue originates from the following line for HTTP requests:

Int64("_tx_duration_ms", time.Until(start).Milliseconds()).

Here, the duration is calculated as the difference between the current time and the request start time in the wrong order (i.e., start time minus now instead of now minus start time).

The same issue exists in the Envoy integration:

Int64("_tx_duration_ms", time.Until(start).Milliseconds()).

So, in both cases time.Since should be used.

Version

0.17.7

On which operating system are you observing this issue?

Linux

In which environment are you deploying?

None

Additional Context

No response

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions