DEV Community

Jihed Ben Arfa
Jihed Ben Arfa

Posted on

Instrumenting a Keycloak SPI provider so the next silent JDBC bug doesn't need a code review to find it

#bugsmash #devchallenge #keycloak #java

Project: keycloak-spi-workbench — custom Keycloak SPI providers, one of them a read-only user storage federation (legacy-user-storage) that reads users from an existing JDBC table instead of forcing a big-bang migration into Keycloak's own store.

What happened first, no Sentry involved: LegacyUserStorageProvider#searchForUserByUserAttributeStream was calling getUserByUsername twice per invocation — once for a null check, once again to build the returned stream:

return getUserByUsername(realm, attrValue) != null
        ? Stream.of(getUserByUsername(realm, attrValue))
        : Stream.empty();
Enter fullscreen mode Exit fullscreen mode

Two calls, two separate JDBC round trips, against a repository with no connection pooling (LegacyUserRepository opens a fresh Connection per query, on purpose — see the repo's README on why). Every username-attribute lookup, twice the DB load it needed. No exception, no wrong result, just silently double the work on every call. Caught by reading the method, not by any tool — fixed by storing the result once and reusing it, with a regression test that fails if it comes back.

That's exactly the kind of bug that's invisible until someone happens to read that method, and the reason I added Sentry next: catching this again shouldn't depend on a code review catching it first.

Where Sentry goes in: LegacyUserRepository's three query methods (findOneWhere, search, count) now open a child span under whatever transaction Keycloak's own request tracing has active — legacy_db.find_one, legacy_db.search — and search records how many rows came back:

private ISpan startSpan(String operation, String description) {
    ISpan parent = Sentry.getSpan();
    return parent != null ? parent.startChild(operation, description) : NoOpSpan.getInstance();
}
Enter fullscreen mode Exit fullscreen mode

Falls back to NoOpSpan when there's no active transaction — never throws, never blocks a login on Sentry being reachable. Any SQLException also gets Sentry.captureException(e) before it's wrapped and rethrown, so a failing legacy database shows up as an event, not just a stack trace in a Keycloak log nobody's tailing.

The part that mattered more than the instrumentation itself: making it opt-in.

@Override
public void init(Config.Scope config) {
    String dsn = System.getenv("SENTRY_DSN");
    if (dsn != null && !dsn.isBlank() && !Sentry.isEnabled()) {
        Sentry.init(options -> {
            options.setDsn(dsn);
            options.setTracesSampleRate(1.0);
            options.setEnvironment(System.getenv().getOrDefault("SENTRY_ENVIRONMENT", "production"));
        });
    }
}
Enter fullscreen mode Exit fullscreen mode

No SENTRY_DSN set, Sentry.init never runs, every span call resolves to NoOpSpan, every captureException call is a no-op. This is a provider other people install into their own Keycloak instance — it doesn't get to assume they want a Sentry account wired into their auth server, and it doesn't get to silently start sending data anywhere without an explicit environment variable making that choice.

Where this actually earns its keep: a per-user JDBC query duplicating itself is the boring, common case. The interesting one is a legacy database that's slow for one specific customer's data shape, or a driver that starts throwing intermittently under load — the search span's result_count and the per-query timing are exactly what would surface a slow query pattern before it shows up as "login is slow" tickets with nothing pointing at the actual repository call underneath.

Top comments (0)