Authenticated user is not logged in http access logs

gautamlihala commented 1 year ago

Describe the bug

For our application, we are generating access logs. The following format is used:

"%h %{REMOTE_USER} %t %{X,trace-id} '%r' %s %b" OR "%h %u %t %{X,trace-id} '%r' %s %b"

The user is injected into the SecurityContext using the @ServerRequestFilter but the value shown always is '-'. Not sure if we are doing something wrong. Attaching a producer

Expected behavior

The user is printed in the access logs with the name "dummy user"

Actual behavior

The value printed is '-'

How to Reproduce?

code-with-quarkus copy.zip

Unzip
Run mvn quarkus:dev
Fire curl http://localhost:8080/hello in another terminal
Check access.log created in the root of the folder. A '-' is present for the Remote_user

Output of `uname -a` or `ver`

Darwin G0QG00Q729 22.5.0 Darwin Kernel Version 22.5.0: Thu Jun 8 22:22:20 PDT 2023; root:xnu-8796.121.3~7/RELEASE_ARM64_T6000 arm64

Output of `java -version`

openjdk version "17.0.7" 2023-04-18 LTS OpenJDK Runtime Environment Zulu17.42+19-CA (build 17.0.7+7-LTS) OpenJDK 64-Bit Server VM Zulu17.42+19-CA (build 17.0.7+7-LTS, mixed mode, sharing)

GraalVM version (if different from Java)

No response

Quarkus version or git rev

3.2.3.Final

Build tool (ie. output of `mvnw --version` or `gradlew --version`)

Apache Maven 3.9.4 (dfbb324ad4a7c8fb0bf182e6d91b0ae20e3d2dd9)

Additional information

No response

gautamlihala commented 1 year ago

Hi,

Any update on this item. Do I need to provide more information or is the information provided correct and apt to investigate it further. Please let me know....

cescoffier commented 1 year ago

It's because you are not integrating with the security architecture of Quarkus. The REMOTE_USER attribute expect a QuarkusHttpUser set from the authentication mechanism from Quarkus.

@sberyozkin may have a better idea how to get this working, but I don't see an easy way without integrating properly.

Alternatively, use another custom attribute to propagate the name into the log.

geoand commented 1 year ago

I would not call this a bug, but a feature request

gautamlihala commented 1 year ago

Hi @cescoffier, @geoand

Whether it is a bug or a feature, I leave that to you guys. But if it comes to priority, I will prefer the former over the latter. :P

On a serious note, I assumed based on the documentation, that when we are referring to the authenticated user, we might look at the Principal instead of quarkus specific class to keep the access log implementation agnostic of it (now that I hear myself, it feels wierd, talking to the people who build the framework to make things agnostic of it)

I will give some background as to why we did not use quarkus-oidc (as it suits most of our use case) and quarkus-security (could not wrap my head around it) to solve our use case.

We have a layered architecture with a front-end and a back-end, and both these apps are running behind a gateway sharing the same domain.

There is no authentication happening on the front-end but the first request after the app loads on the browser is to get user information from the back-end. The back-end intercepts the requests and looks for a cookie (encrypted access token), if not found, generates a request containing the redirect url (with another cookie, this is used to validate the callback) and sends it to the front-end, the front-end redirects the user to sign in containing the callback.

The user signs in and the auth server redirects the user to the callback url which is the endpoint on the back-end. The back-end peeks into the queryparams extracts the state and checks if the cookie send with the redirection request match or not. If a match, then the auth server is requested for a access token, wrapped into a cookie(encrypted) and forwards the request to the user endpoint to provide the user information.

I might have missed some information in our implementation when it comes to customizing the security module of quarkus for our needs.

Another thing is the backend itself is a modular monolith (as at this moment, we do not know we want to go microservices way), so we might end up splitting if the desired performance is not met and authentication can move to a dedicated micro-service but authorization might need to be implemented acrsoss all the micro-services.

Hope to have provided better insight and if any suggestions most welcome.

geoand commented 1 year ago

Looking at our logs, we do actually mention this, so I will reclassify it as a bug

sberyozkin commented 1 year ago

@gautamlihala Hi, is there a reason you are not using quarkus-oidc ? I wonder if your custom JAX-RS filter is running after the REMOTE_USER is checked ?

gautamlihala commented 1 year ago

Hi @sberyozkin,

I have mentioned the rationale above in my previous comments (Please provide your feedback). Attaching a flow diagram to depict the same.

login-flow

Also, the custom Filter is running with the following configuration: @ServerRequestFilter(preMatching = true, priority = 2, nonBlocking = true)

sberyozkin commented 11 months ago

@michalvavrik Hey Michal, please add this one to the queue

michalvavrik commented 11 months ago

Looking at our logs, we do actually mention this, so I will reclassify it as a bug

Only thing I found is _|Remote user that was authenticated | %u | %{REMOTE_USER}_ in the https://quarkus.io/guides/http-reference#configuring-http-access-logs. Could this be documentation issue?

I'll open documentation fix because

I don't see additional value in making Vert.X logging work with REMOTE_USER when literally no other security related feature will work
Please note that @gautamlihala doesn't even rely on quarkus-security extension and doesn't define SecurityIdentity

@gautamlihala I think your expectations are understandable, but should had been corrected by docs. Also it is important to stress there is no actual issue, as you have plenty of options to make this work. I've tried few on your reproducer and this worked:

just don't rely on REMOTE_USER but put it there yourself


diff --git a/src/main/java/org/acme/LoggingFilter.java b/src/main/java/org/acme/LoggingFilter.java
index ba716ce..2d38407 100644
--- a/src/main/java/org/acme/LoggingFilter.java
+++ b/src/main/java/org/acme/LoggingFilter.java
@@ -6,6 +6,9 @@ import org.jboss.resteasy.reactive.server.ServerRequestFilter;

import java.util.UUID;

+import static io.quarkus.vertx.http.runtime.attribute.RemoteUserAttribute.REMOTE_USER; +import static io.quarkus.vertx.http.runtime.attribute.RemoteUserAttribute.REMOTE_USER_SHORT; +

/**

Generic filter to put the trace id into the context @@ -18,7 +21,7 @@ public final class LoggingFilter { *
- @param context request context */
- @ServerRequestFilter(preMatching = true, priority = 1, nonBlocking = true)
- @ServerRequestFilter(preMatching = true, priority = 2, nonBlocking = true) public void getRequestFilter(ContainerRequestContext context) { String traceId = context.getHeaderString(HEADER_TRACE_ID);

@@ -27,5 +30,6 @@ public final class LoggingFilter { context.getHeaders().add(HEADER_TRACE_ID, traceId); } MDC.put(HEADER_TRACE_ID, traceId);

MDC.put("remote-user", context.getSecurityContext().getUserPrincipal().getName()); } } diff --git a/src/main/java/org/acme/SecurityOverrideFilter.java b/src/main/java/org/acme/SecurityOverrideFilter.java index ec7c9b4..e6429cb 100644 --- a/src/main/java/org/acme/SecurityOverrideFilter.java +++ b/src/main/java/org/acme/SecurityOverrideFilter.java @@ -16,7 +16,7 @@ public final class SecurityOverrideFilter { *
- @param requestContext context of the request received */
@ServerRequestFilter(preMatching = true, priority = 2, nonBlocking = true)
@ServerRequestFilter(preMatching = true, priority = 1, nonBlocking = true) public void performAuth(ContainerRequestContext requestContext) { User user = new User("dummy user"); requestContext.setSecurityContext(new SecurityContext() { diff --git a/src/main/resources/application.yml b/src/main/resources/application.yml index 00c696e..f5f649b 100644 --- a/src/main/resources/application.yml +++ b/src/main/resources/application.yml @@ -2,7 +2,7 @@ quarkus: http: access-log: enabled: true
pattern: "%h %{REMOTE_USER} %t %{X,trace-id} '%r' %s %b"
pattern: "%h %{X,remote-user} %t %{X,trace-id} '%r' %s %b" log-to-file: true base-file-name: access rotate: daily


2. set user to the event

diff --git a/src/main/java/org/acme/SecurityOverrideFilter.java b/src/main/java/org/acme/SecurityOverrideFilter.java index ec7c9b4..ecce5ca 100644 --- a/src/main/java/org/acme/SecurityOverrideFilter.java +++ b/src/main/java/org/acme/SecurityOverrideFilter.java @@ -1,16 +1,29 @@ package org.acme;

+import io.quarkus.security.credential.Credential; +import io.quarkus.security.identity.CurrentIdentityAssociation; +import io.quarkus.security.identity.SecurityIdentity; +import io.quarkus.vertx.http.runtime.security.QuarkusHttpUser; +import io.smallrye.mutiny.Uni; +import io.vertx.ext.web.RoutingContext; +import jakarta.inject.Inject; import jakarta.ws.rs.container.ContainerRequestContext; import jakarta.ws.rs.core.SecurityContext; import org.jboss.resteasy.reactive.server.ServerRequestFilter;

+import java.security.Permission; import java.security.Principal; +import java.util.Map; +import java.util.Set;

/**

Security filter to process incoming request for authentication and authorization. If not authenticated, then redirect */ public final class SecurityOverrideFilter {

@Inject
RoutingContext routingContext;
/**
- Filter to perform authentication and authorization
- @@ -18,6 +31,57 @@ public final class SecurityOverrideFilter { */ @ServerRequestFilter(preMatching = true, priority = 2, nonBlocking = true) public void performAuth(ContainerRequestContext requestContext) {
routingContext.setUser(new QuarkusHttpUser(new SecurityIdentity() {
@Override
public Principal getPrincipal() {
return new Principal() {
@Override
public String getName() {
return "dummy user";
}
};
}
@Override
public boolean isAnonymous() {
return false;
}
@Override
public Set getRoles() {
return null;
}
@Override
public boolean hasRole(String s) {
return false;
}
@Override
public T getCredential(Class aClass) {
return null;
}
@Override
public Set getCredentials() {
return null;
}
@Override
public T getAttribute(String s) {
return null;
}
@Override
public Map<String, Object> getAttributes() {
return null;
}
@Override
public Uni checkPermission(Permission permission) {
return null;
}
})); User user = new User("dummy user"); requestContext.setSecurityContext(new SecurityContext() { @Override

michalvavrik commented 11 months ago

looks like this issue helped to uncover bug - identity augmented by SecurityContext wasn't logged properly, so users relying only on Jakarta REST concept would run into issue, fix is here https://github.com/quarkusio/quarkus/pull/37407. thanks

gautamlihala commented 11 months ago

@michalvavrik, thanks for the efforts....

Probably I used too many words but did not point to what I thought was the issue actually.

I actually used the MDC route to solve this. For me it was no issue if the documentation was incorrect as long as I knew which path to take. But if it is also solved for jaxrs then I am more than happy.

Glad I could help in finding the bug indirectly. 😝

Thanks again.

quarkusio / quarkus