Robbert van Waveren opened SPR-17507 and commented
Expected behavior: Every HTTP request is logged with a unique log prefix regardless of any tcp/ip connection or thread reuse.
Observed behavior: Consecutive HTTP requests from Chrome (using keep-alive) that are handled by the same reactor-http-nio thread are logged with the same log prefix.
Affects: 5.1.2
Attachments: - issue-project.zip (9.08 kB)
Issue Links: - #22038 HTTP GET from Chrome with WebFlux Rest Controller never completes
Comment From: spring-projects-issues
Rossen Stoyanchev commented
We use the channel id, intentionally matching to what Reactor Netty does. I see your point about the fact that connections are pooled and re-used. At the same time requests on the same connection do not overlap, so it doesn't prevent correctly correlating messages. It also provides a bit of extra information by showing that the same connection is being used, or not (when a connection is closed and re-opened).
Comment From: spring-projects-issues
Robbert van Waveren commented
I've noticed that too and after reading the Javadocs it is somewhat clear to me that this can happen. Exposing it as ServerHttpRequest#getId though kind of makes it less obvious as id suggests uniqueness.
Perhaps this ticket could be changed to an improvement request to for example make a separate getId and getChannelId available in the ServerWebExchange and ServerHttpRequest interfaces, if that is something you would want to support. As I feel that having truely unique http request id's would have a lot of value, especially assuming more and more requests will get multiplexed over the same channel in the future with http2 and 3.
Comment From: spring-projects-issues
Rossen Stoyanchev commented
For other servers we use an identity hex on the request instance, because a channel or connection id is not available. So having a separate getChannelId doesn't really make sense, as we couldn't implement it consistently across servers.
The main purpose of the getId() method is for logging purposes. We could consider appending "-N" to the id where N is an incremental number to make it unique, but I'm not convinced that's really necessary. Overall I'd really like to remain aligned with what Reactor Netty uses. Good point though about HTTP/2 where we might need to append a stream id as well. I will discuss this with the Reactor Netty team.
Comment From: spring-projects-issues
Rossen Stoyanchev commented
Scheduling tentatively for 5.2 as we should consider an improvement for HTTP/2 streams.
Comment From: spring-projects-issues
Rossen Stoyanchev commented
I've created Reactor Netty #549 which we'll need in order to access the stream id.
Comment From: GwiYeong
Hi. any update for this issue? i came from this link that i asked stackoverflow.
what is status: blocked means?
any workaround to get unique string for each requests?
Comment From: snicoll
@GwiYeong there is a description for each label:
An issue that's blocked on an external project change
The comment above yours has a link to an unresolved issue in the reactor-netty project that we need to move further.
Comment From: rstoyanchev
HTTP/2 streams should be addressed as part of https://github.com/reactor/reactor-netty/issues/549 and it looks like that will be transparent to us. In general where the underlying server exposes a connection id, we will use that, so if you need something further I believe that should be done at the Reactor Netty level. Otherwise the logs between Reactor Netty and WebFlux won't be entirely consistent.
Comment From: PyvesB
We've enabled debug logging for incoming web server requests and have bumped into this issue as well. The Javadocs of ServerWebExchange suggest that the log prefix can be used to correlate messages for a given exchange: https://github.com/spring-projects/spring-framework/blob/daa30a9f0b6bcc33cbb452e7a1df27776acfa935/spring-web/src/main/java/org/springframework/web/server/ServerWebExchange.java#L221
However, as the underlying channel id is being used (see here), the same log prefix may be duplicated across different requests (for example if the connection is kept alive). Logs for different requests and responses will end up being mixed up together due to this.
@rstoyanchev suggestion about appending "-N" to the id where N is an incremental number to make it unique would be ideal, as it would prevent exchanges being confused with one another whilst still allowing to correlate with underlying reactor-netty log messages.
Could this issue please be reopened?
Comment From: PyvesB
Thanks for working on this @rstoyanchev! 👍
Comment From: pdevalck
I created issue #26430 for the Undertow reactive server