Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

HTTP 400 Bad Request being marked as a false positive server error in Keycloak #7288

Open
froque opened this issue Jul 5, 2024 · 6 comments

Comments

@froque
Copy link

froque commented Jul 5, 2024

Running keycloak:

wget -nc --quiet https://github.com/DataDog/dd-trace-java/releases/download/v1.37.0/dd-java-agent-1.37.0.jar
docker run \
    -d \
    --rm \
    --name keycloak  \
    --network host \
    -e KEYCLOAK_ADMIN=admin \
    -e KEYCLOAK_ADMIN_PASSWORD=admin \
    -e "KC_HTTP_RELATIVE_PATH=/auth" \
    -e DD_SERVICE=keycloak \
    -e DD_WRITER_TYPE=LoggingWriter \
    -e DD_HTTP_SERVER_ROUTE_BASED_NAMING="false" \
    -e JAVA_TOOL_OPTIONS="-javaagent:/opt/dd-java-agent.jar" \
    -v $(pwd)/dd-java-agent-1.37.0.jar:/opt/dd-java-agent.jar:ro \
    quay.io/keycloak/keycloak \
        start-dev

make a HTTP request to token endpoint with an expired or invalid refresh token

❯ curl -i -s \
  -d "client_id=account" \
  -d "refresh_token=some_invalid_refresh_token" \
  -d "grant_type=refresh_token" \
  "http://localhost:8080/auth/realms/master/protocol/openid-connect/token"
HTTP/1.1 400 Bad Request
Cache-Control: no-store
Pragma: no-cache
content-length: 69
Content-Type: application/json
Referrer-Policy: no-referrer
Strict-Transport-Security: max-age=31536000; includeSubDomains
X-Content-Type-Options: nosniff
X-Frame-Options: SAMEORIGIN
X-XSS-Protection: 1; mode=block

{"error":"invalid_grant","error_description":"Invalid refresh token"}
docker logs keycloak >& dd-java-agent.log
docker stop keycloak
❯ grep "POST /auth/realms/master/protocol/openid-connect/token" dd-java-agent.log | cut -b 139-|jq ".[2]"  
{
  "service": "keycloak",
  "name": "jakarta-rs.request",
  "resource": "TokenEndpoint.processGrantRequest",
  "trace_id": 7190010773749954000,
  "span_id": 560244054904225900,
  "parent_id": 1901844586656103700,
  "start": 1720217563891473700,
  "duration": 87481836,
  "type": "web",
  "error": 1,
  "metrics": {
    "thread.id": 53
  },
  "meta": {
    "error.stack": "org.keycloak.services.CorsErrorResponseException: invalid_grant\n\tat org.keycloak.protocol.oidc.grants.RefreshTokenGrantType.process(RefreshTokenGrantType.java:101)\n\tat org.keycloak.protocol.oidc.endpoints.TokenEndpoint.processGrantRequest(TokenEndpoint.java:140)\n\tat org.keycloak.protocol.oidc.endpoints.TokenEndpoint$quarkusrestinvoker$processGrantRequest_6408e15340992839b66447750c221d9aaa837bd7.invoke(Unknown Source)\n\tat org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)\n\tat io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)\n\tat org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)\n\tat java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)\n\tat java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)\n\tat io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:582)\n\tat org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)\n\tat org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)\n\tat org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)\n\tat org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)\n\tat io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)\n\tat java.base/java.lang.Thread.run(Thread.java:1583)\n",
    "component": "jakarta-rs-controller",
    "error.type": "org.keycloak.services.CorsErrorResponseException",
    "thread.name": "executor-thread-1",
    "error.message": "invalid_grant"
  }
}

We initially though this was a problem in Keycloak keycloak/keycloak#29451 fixed by keycloak/keycloak#29649 but now it seems to be a problem in dd-java-agent.

image

@vandonr
Copy link
Contributor

vandonr commented Jul 8, 2024

Hello, thank you for the report.
This is marked as an error because it generates an Exception that is not handled within the scope of the span. You can see that the root span for that request (which is also the one bearing the http response code) is not marked as error.
What exactly is the behavior you would like to see ?

I see from the screenshot that you are using error tracking, you can mark the issue as "Ignored" if you don't want to see it in the issues list.

@froque
Copy link
Author

froque commented Jul 8, 2024

What exactly is the behavior you would like to see ?

Since from the HTTP client perspective the response is a HTTP 400 and not HTTP 5xx, I was expecting Datadog to not mark this as an error.

I see from the screenshot that you are using error tracking, you can mark the issue as "Ignored" if you don't want to see it in the issues list.

I missed that. I am going to try it now.

@vandonr
Copy link
Contributor

vandonr commented Jul 8, 2024

The thing is that where the error is captured, we just see it as an exception being thrown by a Java service, which we record as an error. We don't have information on the HTTP response code at this point in time. When we handle the actual response code, we see it's a 400 and we do not mark that span as error.

I know it's not your code but an open source project, but maybe the issue is that keycloak is using an Exception to handle code flow in a not-so-exceptional situation, which is something regarded as bad practice when writing Java code.
One fix would be to rework that code to use a meaningful return status rather than an exception.

@froque
Copy link
Author

froque commented Jul 8, 2024

Ok. In that case, perhaps a new config similar to DD_TRACE_CLASSES_EXCLUDE and DD_HTTP_SERVER_ERROR_STATUSES to ignore specific exceptions (DD_TRACE_EXCEPTIONS_EXCLUDE)?

@Xyaren
Copy link
Contributor

Xyaren commented Jul 10, 2024

Or even better let us define some Java class that can decide if a specific exception should be regarded as an error or not i.e. by looking into the type, attributes or annotations.

This would also allow for a fix for #7141.

@michaz
Copy link

michaz commented Sep 16, 2024

using an Exception to handle code flow in a not-so-exceptional situation, which is something regarded as bad practice when writing Java code

Java web frameworks encourage throwing Exceptions from an endpoint method whenever it cannot return a thing of the type it usually returns. The pattern is:

  • The return type of your endpoint method is the type of your usual 200 response.
  • When you cannot return a value of that type, you throw an exception, which is mapped to a http response by the framework.
@Path("animals")
public class AnimalResource {

    @GET
    @Path("{animal-id}")
    public Animal getAnimal(@PathParam("animal-id") String animalId) {
        Animal result = Database.findAnimal(animalId);
        if (result == null) {
            throw new WebApplicationException("Animal not found", 404);
        }
        return result;
    }

}

When Datadog traces this method, it has to make some kind of decision about whether the Exception is "4xx-like" or "5xx-like". Perhaps it needs to know the framework and its exception handling conventions to decide that. Or perhaps it can defer the decision until the enclosing http span knows the http status code. Anyway, this pattern is not only valid but normal.

Datadog cannot know about arbitrary methods of course. But if Datadog auto-detects e.g. JAX-RS methods like this and says it can trace them, it seems to imply that Datadog wants to find a way to interpret exceptions thrown from it, just like it interprets what the web server is doing when it is setting a status code.

(Currently this isn't working, and I think it used to work somehow, but I can't be sure of course.)

Maybe fits better in #7141 but I think it may be the same issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants