Skip to content

Conversation

@devinrsmith
Copy link
Member

Logs the session ID and user-agent (if set) on session creation. Technically, the user-agent could change with each RPC call, but that is not something that clients typically do. For contexts where logging every session is too spammy, the configuration property SessionListenerLogger.level can be used to set the appropriate log level.

Note, the user agent interceptor is not able to be bound to Set<ServerInterceptor> as it causes an undefined ordering with respect to SessionServiceInterceptor; we need to ensure that the user agent interceptor is applied before the session service interceptor.

Server component of #5704

Logs the session ID and user-agent (if set) on session creation. Technically, the user-agent could change with each RPC call, but that is not something that clients typically do. For contexts where logging every session is too spammy, the configuration property `SessionListenerLogger.level` can be used to set the appropriate log level.

Note, the user agent interceptor is not able to be bound to `Set<ServerInterceptor>` as it causes an undefined ordering with respect to `SessionServiceInterceptor`; we need to ensure that the user agent interceptor is applied before the session service interceptor.

Server component of deephaven#5704
@devinrsmith devinrsmith added this to the 0.37.0 milestone Aug 27, 2024
@devinrsmith devinrsmith requested a review from niloc132 August 27, 2024 20:26
@devinrsmith devinrsmith self-assigned this Aug 27, 2024
@devinrsmith
Copy link
Member Author

Here's an example of connecting from a browser:

2024-08-27T20:28:25.263Z | qtp1540031691-111    |  INFO | s.s.SessionListenerLogger | onSessionCreated, id=273f26d4-53f9-4f3c-a118-0d317348a42e, userAgent=Mozilla/5.0 (X11; Linux x86_64; rv:129.0) Gecko/20100101 Firefox/129.0

Here's an example of connect-check:

2024-08-27T20:29:00.030Z | qtp1540031691-111    |  INFO | s.s.SessionListenerLogger | onSessionCreated, id=a3adb37e-6710-45c2-b45b-46f1c2e9a9df, userAgent=grpc-java/1.58.0 (deephaven/0.37.0-SNAPSHOT; deephaven-session-examples) grpc-java-netty/1.58.0

@Inject
public SessionListenerLogger() {
level = LogLevel.valueOf(Configuration.getInstance().getStringForClassWithDefault(SessionListenerLogger.class,
"level", LogLevel.INFO.getName()));
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why make this configurable, instead of the usual approach of "change the class's log level"? There is only one log message in this class, so enabling/disabling the log level seems like it should do it.

Frustrating to find that this can only be configured from the xml file, at least with our current setup...

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm also not sure that this is enough to really address the class of issues we were seeing - we only will see it on connection, rather than paired with the thing that went wrong.

It isn't quite right to pair the authenticated user agent with the exec/auth context, but it would be closer to attach the current request's auth context to the exec context so we can see it for a given grpc call, and dump it in case of an error?

Copy link
Member Author

@devinrsmith devinrsmith Sep 12, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why make this configurable

It's mostly just the (lack of) configurability of the logging XML; instead of doing this, I could just make it debug, or removal it altogether.

It isn't quite right to pair the authenticated user agent with the exec/auth context, but it would be closer to attach the current request's auth context to the exec context so we can see it for a given grpc call, and dump it in case of an error?

I might instead suggest that our error logging sites just call and log UserAgentContext.get() directly. In that way, we don't need to attach anything to the auth context.

What was the specific error we were seeing where user-agent would have been helpful?


public final class UserAgentContext {

private static final String USER_AGENT_HEADER = "user-agent";
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just a heads up that this is going to seem inconsistent for now from browsers - using h2/https, browsers will report their plain user-agent header, while using http (and websockets) this will be empty. Neither is correct for grpc - the user-agent header is not correct to read for grpc-web calls, since browsers do not permit web applications to write this (so we can't get our own versions in there). Instead, clients must set x-user-agent, and our GrpcWebFilter most replace this.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It's probably useful for our server to get the browser user agents, at least in the context of h2. Seems like we might want to unconditionally attach x-user-agent info too, or are you saying that GrpcWebFilter should take the value from x-user-agent and shove it into user-agent?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants