Skip to content
New issue

Have a question about this project? # for a free GitHub account to open an issue and contact its maintainers and the community.

#

By clicking “#”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? # to your account

http (fix): Fail to read RPCContext if the response Rx is evaluated in a different thread #3863

Draft
wants to merge 1 commit into
base: main
Choose a base branch
from
Draft

http (fix): Fail to read RPCContext if the response Rx is evaluated in a different thread #3863

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
23 changes: 21 additions & 2 deletions airframe-http-netty/src/test/scala/wvlet/airframe/http/netty/NettyLoggingTest.scala
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -13,16 +13,19 @@
*/
package wvlet.airframe.http.netty

import wvlet.airframe.http.*
import wvlet.airframe.http.HttpLogger.InMemoryHttpLogger
import wvlet.airframe.http.{Http, HttpLogger, HttpServer, RPC, RPCContext, RxRouter}
import wvlet.airframe.http.HttpMessage.Response
import wvlet.airframe.http.client.SyncClient
import wvlet.airframe.http.netty.NettyRxFilterTest.router1
import wvlet.airframe.rx.Rx
import wvlet.airspec.AirSpec
import wvlet.log.LogSupport
import wvlet.log.io.IOUtil

import scala.collection.immutable.ListMap

object NettyLoggingTest extends AirSpec {
private val port = IOUtil.unusedPort

@RPC
class MyRPC extends LogSupport {
Expand All @@ -35,6 +38,14 @@
requestCount += 1
trace("hello rpc")
}

def async(): Rx[Response] = {
RPCContext.current.setThreadLocal("user", "zzzz-xxxx")
Http.client
.newAsyncClient(s"localhost:${port}").send(
Http.POST("/wvlet.airframe.http.netty.NettyLoggingTest.MyRPC/hello")
)
}
}

private var clientLogger: InMemoryHttpLogger = null
Expand All @@ -44,6 +55,7 @@
_.add(
Netty.server
.withRouter(RxRouter.of[MyRPC])
.withPort(port)
.withHttpLogger { config =>
serverLogger = new InMemoryHttpLogger(config)
serverLogger
Expand Down Expand Up @@ -95,6 +107,13 @@
clientLogEntry shouldContain ("custom_log_entry" -> "log-test-client")
}

test("async server response") {
syncClient.send(Http.POST("/wvlet.airframe.http.netty.NettyLoggingTest.MyRPC/async"))
val logEntry = serverLogger.getLogs.last
debug(logEntry)
logEntry shouldContain ("user" -> "zzzz-xxxx")

Check failure on line 114 in airframe-http-netty/src/test/scala/wvlet/airframe/http/netty/NettyLoggingTest.scala

View workflow job for this annotation

GitHub Actions / Scala 2.12

NettyLoggingTest.async server response 

Map(server_name -> log-test-server, method -> POST, response_header -> ListMap(content_length -> 0, x_airframe_rpc_status -> 0), duration_ms -> 0, path -> /wvlet.airframe.http.netty.NettyLoggingTest.MyRPC/async, status_code_name -> OK, response_content_length -> 0, uri -> /wvlet.airframe.http.netty.NettyLoggingTest.MyRPC/async, event_timestamp -> 2025-03-05T20:36:39.927Z, status_code -> 200, start_time_ms -> 1741206999927, rpc_status -> 0, rpc_status_name -> SUCCESS_S0, end_time_ms -> 1741206999927, time -> 1741206999, custom_log_entry -> test, request_header -> ListMap(upgrade -> h2c, connection -> Upgrade, HTTP2-Settings, content_length -> 0, http2_settings -> AAEAAEAAAAIAAAAAAAMAAAAAAAQBAAAAAAUAAEAAAAYABgAA, user_agent -> Java-http-client/21.0.6, host -> localhost:37359), remote_address -> 127.0.0.1:59178) doesn't contain (user,zzzz-xxxx)

Check failure on line 114 in airframe-http-netty/src/test/scala/wvlet/airframe/http/netty/NettyLoggingTest.scala

View workflow job for this annotation

GitHub Actions / Scala 2.13

NettyLoggingTest.async server response 

ListMap(custom_log_entry -> test, server_name -> log-test-server, time -> 1741207003, start_time_ms -> 1741207003459, event_timestamp -> 2025-03-05T20:36:43.459Z, method -> POST, path -> /wvlet.airframe.http.netty.NettyLoggingTest.MyRPC/async, uri -> /wvlet.airframe.http.netty.NettyLoggingTest.MyRPC/async, remote_address -> 127.0.0.1:37292, request_header -> ListMap(upgrade -> h2c, http2_settings -> AAEAAEAAAAIAAAAAAAMAAAAAAAQBAAAAAAUAAEAAAAYABgAA, connection -> Upgrade, HTTP2-Settings, content_length -> 0, user_agent -> Java-http-client/21.0.6, host -> localhost:36823), end_time_ms -> 1741207003459, duration_ms -> 0, status_code -> 200, status_code_name -> OK, response_content_length -> 0, rpc_status -> 0, rpc_status_name -> SUCCESS_S0, response_header -> ListMap(content_length -> 0, x_airframe_rpc_status -> 0)) doesn't contain (user,zzzz-xxxx)
logEntry shouldContain ("rpc_method" -> "async")
}

Check failure on line 116 in airframe-http-netty/src/test/scala/wvlet/airframe/http/netty/NettyLoggingTest.scala

View workflow job for this annotation

GitHub Actions / Scala 3.6.x

NettyLoggingTest.async server response 

ListMap(custom_log_entry -> test, server_name -> log-test-server, time -> 1741206989, start_time_ms -> 1741206989052, event_timestamp -> 2025-03-05T20:36:29.052Z, method -> POST, path -> /wvlet.airframe.http.netty.NettyLoggingTest.MyRPC/async, uri -> /wvlet.airframe.http.netty.NettyLoggingTest.MyRPC/async, remote_address -> 127.0.0.1:38300, request_header -> ListMap(upgrade -> h2c, http2_settings -> AAEAAEAAAAIAAAAAAAMAAAAAAAQBAAAAAAUAAEAAAAYABgAA, connection -> Upgrade, HTTP2-Settings, content_length -> 0, user_agent -> Java-http-client/21.0.6, host -> localhost:35093), end_time_ms -> 1741206989052, duration_ms -> 0, status_code -> 200, status_code_name -> OK, response_content_length -> 0, rpc_status -> 0, rpc_status_name -> SUCCESS_S0, response_header -> ListMap(content_length -> 0, x_airframe_rpc_status -> 0)) doesn't contain (user,zzzz-xxxx)

Check failure on line 116 in airframe-http-netty/src/test/scala/wvlet/airframe/http/netty/NettyLoggingTest.scala

View workflow job for this annotation

GitHub Actions / Scala 3

NettyLoggingTest.async server response 

ListMap(custom_log_entry -> test, server_name -> log-test-server, time -> 1741207002, start_time_ms -> 1741207002185, event_timestamp -> 2025-03-05T20:36:42.185Z, method -> POST, path -> /wvlet.airframe.http.netty.NettyLoggingTest.MyRPC/async, uri -> /wvlet.airframe.http.netty.NettyLoggingTest.MyRPC/async, remote_address -> 127.0.0.1:46478, request_header -> ListMap(upgrade -> h2c, http2_settings -> AAEAAEAAAAIAAAAAAAMAAAAAAAQBAAAAAAUAAEAAAAYABgAA, connection -> Upgrade, HTTP2-Settings, content_length -> 0, user_agent -> Java-http-client/21.0.6, host -> localhost:37667), end_time_ms -> 1741207002185, duration_ms -> 0, status_code -> 200, status_code_name -> OK, response_content_length -> 0, rpc_status -> 0, rpc_status_name -> SUCCESS_S0, response_header -> ListMap(content_length -> 0, x_airframe_rpc_status -> 0)) doesn't contain (user,zzzz-xxxx)

Check failure on line 116 in airframe-http-netty/src/test/scala/wvlet/airframe/http/netty/NettyLoggingTest.scala

View workflow job for this annotation

GitHub Actions / Scala 3 / JDK17

NettyLoggingTest.async server response 

ListMap(custom_log_entry -> test, server_name -> log-test-server, time -> 1741207008, start_time_ms -> 1741207008123, event_timestamp -> 2025-03-05T20:36:48.123Z, method -> POST, path -> /wvlet.airframe.http.netty.NettyLoggingTest.MyRPC/async, uri -> /wvlet.airframe.http.netty.NettyLoggingTest.MyRPC/async, remote_address -> 127.0.0.1:44790, request_header -> ListMap(upgrade -> h2c, http2_settings -> AAEAAEAAAAIAAAAAAAMAAAAAAAQBAAAAAAUAAEAAAAYABgAA, connection -> Upgrade, HTTP2-Settings, content_length -> 0, user_agent -> Java-http-client/17.0.14, host -> localhost:46489), end_time_ms -> 1741207008123, duration_ms -> 0, status_code -> 200, status_code_name -> OK, response_content_length -> 0, rpc_status -> 0, rpc_status_name -> SUCCESS_S0, response_header -> ListMap(content_length -> 0, x_airframe_rpc_status -> 0)) doesn't contain (user,zzzz-xxxx)
}

}
6 changes: 5 additions & 1 deletion airframe-http/src/main/scala/wvlet/airframe/http/internal/RPCResponseFilter.scala
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,11 @@ import scala.util.{Failure, Success}
class RPCResponseFilter(httpLogger: HttpLogger) extends RxHttpFilter with LogSupport {
override def apply(request: HttpMessage.Request, next: RxHttpEndpoint): Rx[HttpMessage.Response] = {

def logContext = new HttpLogs.LogContext(request, httpLogger, None, Some(RPCContext.current))
// Note: RPCContext is not set before calling next(request), so
// We need to lazily evaluate the RPCContext
def logContext = {
new HttpLogs.LogContext(request, httpLogger, None, Some(RPCContext.current))
}

next(request)
.transform {
Expand Down
Loading