[Frontend] Add request arrival log

[ApsarasX]

Purpose

Currently, logs stating Received request ...... are only output after the request has been encoded by the tokenizer. However, the timing of this log does not reflect the actual arrival time of the request.

Therefore, I have added an additional log to record the moment the request arrives.

Test Plan

Test Result

---

Essential Elements of an Effective PR Description Checklist

• The purpose of the PR, such as "Fix some issue (link existing issues this PR will resolve)".
• The test plan, such as providing test command.
• The test results, such as pasting the results comparison before and after, or e2e results
• (Optional) The necessary documentation update, such as updating supported_models.md and examples for a new model.
• (Optional) Release notes update. If your change is user facing, please update the release notes draft in the Google Doc.

[github-actions]

👋 Hi! Thank you for contributing to the vLLM project.

💬 Join our developer Slack at https://slack.vllm.ai to discuss your PR in #pr-reviews, coordinate on features in #feat- channels, or join special interest groups in #sig- channels.

Just a reminder: PRs would not trigger full CI run by default. Instead, it would only run fastcheck CI which starts running only a small and essential subset of CI tests to quickly catch errors.

You ask your reviewers to trigger select CI tests on top of fastcheck CI.

Once the PR is approved and ready to go, your PR reviewer(s) can run CI to test the changes comprehensively before merging.

To run CI, PR reviewers can either: Add ready label to the PR or enable auto-merge.

If you have any questions, please reach out to us on Slack at https://slack.vllm.ai.

🚀

[gemini-code-assist]

Code Review

This pull request introduces a request arrival log to better track the actual arrival time of requests, which is a valuable addition for monitoring and debugging. The implementation is mostly consistent across the various serving entrypoints. I've pointed out one minor inconsistency in the logging approach that should be addressed to maintain a unified logging strategy.

[chaunceyjiang]

1. Can we use FastAPI middleware to accomplish this?
2. Under high concurrency and a large volume of requests, excessive log output may not be a good idea.
3. We already have a similar feature in place—why doesn’t it meet your needs? Could you please describe this in more detail?

[ApsarasX]

1. Can we use FastAPI middleware to accomplish this?
2. Under high concurrency and a large volume of requests, excessive log output may not be a good idea.
3. We already have a similar feature in place—why doesn’t it meet your needs? Could you please describe this in more detail?

1. The arrivial logging relies on the request_id, so we shouldn't handle it in middleware unless we also move the request_id generation there.
2. With this PR, we're only adding a single log line per request. I don't think that's gonna hurt performance even with high concurrency, and I'll run some tests to prove it.
3. For batch inference with very long prompts (up to 100k tokens), the tokenizer.encode step can introduce significant overhead, so it's critical to log when the request arrives rather than when processing begins.

[markmc]

@ApsarasX "it's critical to log when the request arrives" ... could you describe why in more detail? What are you doing with this timing information?

@chaunceyjiang We could make this a DEBUG level log. In any case, it will require --enable-log-requests to be enabled, which I expect is generally not enabled in high concurrency environments

See also #26708