Multi-Tenant Debugging with Spring Boot: Optimizing Log Levels for Specific Tenants

In enterprise applications, logs play an important role. They allow you to investigate failures and understand sequences of events and flows.

The most widely used are the following log levels:

1. DEBUG: The DEBUG level designates fine-grained informational events that are most useful to debug an application.
2. INFO: The INFO level designates informational messages that highlight the application's progress at a coarse-grained level.
3. WARN: The WARN level designates potentially harmful situations.

The default log level for most applications is INFO — which means that DEBUG (and TRACE) logs will not reach the log file. And sometimes when the application doesn’t behave as expected for specific inputs (and also doesn’t fail), we need to have more granular logs. A typical way of changing log levels is per class or per package. For instance, you can set the following values in application.properties file to enable debugging:

logging.level.org.springframework.web=debug
logging.level.com.example.you_app.YourClass=debug

The problem

If we have an application that serves lots of requests, enabling debug per package or even in a specific class can produce lots of unnecessary I/O or even hit your monthly quota if you’re using external services like Logz.io. When debugging a specific case (specific request, specific tenant), we would love to enable debug ONLY for it.

In this article, we will see how to build a Spring Boot application that will allow setting log level to DEBUG only for specific tenants in a multi-tenant application by updating properties. Technical issues that we will face:

• controlling log level per-thread (in addition to per class/per-package)
• accessing template/path variables in request URL before controller
• unit-testing logs output

The setup

Application source code is available on github

The application will need a minimum set of dependencies:

dependencies {
    // for starting web context
    implementation 'org.springframework.boot:spring-boot-starter-web'

    // we'll need this to update props at runtime
    implementation 'org.springframework.boot:spring-boot-starter-actuator'
    implementation 'org.springframework.cloud:spring-cloud-context'
}

Configuring Logback filter

Logback, a logging framework used in this application, uses the mechanism of filters in order to decide whether specific log event should be logged or ignored.

Also, logback-classic defines class ch.qos.logback.classic.turbo.MDCFilter that relies on thread-local MDC (Mapping Diagnostic Context) to determine whether event should be logged or not.

public class MDCFilter extends MatchingFilter {

    String MDCKey;
    String value;

    @Override
    public FilterReply decide(Marker marker, Logger logger, Level level, String format, Object[] params, Throwable t) {
        if (MDCKey == null) {
            return FilterReply.NEUTRAL;
        }

        String value = MDC.get(MDCKey);
        if (this.value.equals(value)) {
            return onMatch;
        }
        return onMismatch;
    }

    public void setValue(String value) {
        this.value = value;
    }

    public void setMDCKey(String MDCKey) {
        this.MDCKey = MDCKey;
    }

}

We can extend it and add some logic specific to our use case:

public class TenantDebugMdcFilter extends MDCFilter {

    @Override
    public FilterReply decide(
           Marker marker, Logger logger, Level level, 
           String format, Object[] params, Throwable t
    ) {
        if (level != Level.DEBUG) {
            return FilterReply.NEUTRAL;
        }
        if (logger.getName().startsWith("examples.debuggingtenant")) {
            return super.decide(marker, logger, level, format, params, t);
        }
        return FilterReply.NEUTRAL;
    }
}

E.g. we’re only interested in allowing thread-local debugging for debug logs in our application.

Now we need to configure it and add it to our application

@Configuration
class TenantDebuggingConfiguration {
    public static final String TENANT_DEBUGGING_MDC_KEY = "tenant-log-level";
    public static final String TENANT_DEBUG_LEVEL = "enabled";

    @Autowired
    public TenantDebuggingConfiguration() {
        LoggerContext loggerContext = 
                   (LoggerContext) LoggerFactory.getILoggerFactory();

        MDCFilter filter = new TenantDebugMdcFilter();
        filter.setMDCKey(TENANT_DEBUGGING_MDC_KEY);
        filter.setValue(TENANT_DEBUG_LEVEL);
        filter.setOnMatch("ACCEPT");

        loggerContext.addTurboFilter(filter);
    }
}

This configuration means the following: if any part of our application will set key tenant-log-level (can be any by your choice) with value enabled (also can be anything), then TenantDebugMdcFilter will indicate that all debug events should be logged.

Resolving current tenant from request

The logic of setting MDC flag can be any. Let’s just assume that all our tenant-specific endpoints have a “tenant-id” path variable in URL. E.g., our controller will look like this:

@RestController
@Slf4j
public class ControllerForTenantWithDebug {
    @GetMapping("/api/tenants/{" + TENANT_ID_TEMPLATE_VAR + "}/action")
    public void doLogSomething(
            @PathVariable(TENANT_ID_TEMPLATE_VAR) String tenantId
    ) {
        log.info("Info log that we got request from tenant {}", tenantId);
        log.debug("And here is some debug data for tenant {}", tenantId);
    }

}

And now we’ll need to create a component that will set MDC property before flow reaches our controller. Logic will be following:

• we need the environment to contain something in tenants-for-debugging property
• next, we extract framework-provided attribute from request (HandlerMapping.URI_TEMPLATE_VARIABLES_ATTRIBUTE) and check the value of “tenant-id” path variable before reaching the controller

@Component
@RequiredArgsConstructor
public class TenantDebuggingHandlerInterceptor implements HandlerInterceptor {

    public static final String TENANT_ID_TEMPLATE_VAR = "tenant-id";

    private final PropertyResolver propertyResolver;

    @Override
    public boolean preHandle(
          HttpServletRequest request, 
          HttpServletResponse response, Object handler) throws Exception {
        Set tenantsForDebugging = propertyResolver.getProperty(
                "tenants-for-debugging", Set.class, Set.of()
        );
        if (tenantsForDebugging.isEmpty()) {
            return true;
        }
        Map<String, String> templateVariables = 
            (Map<String, String>) request.getAttribute(
                  HandlerMapping.URI_TEMPLATE_VARIABLES_ATTRIBUTE
            );
        if (ObjectUtils.isEmpty(templateVariables)) {
            return true;
        }
        if (!templateVariables.containsKey(TENANT_ID_TEMPLATE_VAR)) {
            return true;
        }
        String pathVarValue = templateVariables.get(TENANT_ID_TEMPLATE_VAR);
        if (tenantsForDebugging.contains(pathVarValue)) {
            MDC.put(TENANT_DEBUGGING_MDC_KEY, TENANT_DEBUG_LEVEL);
        }
        return true;
    }

    @Override
    public void postHandle(
          HttpServletRequest request, HttpServletResponse response, 
          Object handler, ModelAndView modelAndView) throws Exception {
        MDC.remove(TENANT_DEBUGGING_MDC_KEY);
    }

}

And lastly, this bean needs to be added to Spring’s interceptor registry via registering WebMvcConfigurer bean

@Bean
public WebMvcConfigurer interceptorsConfigurer(TenantDebuggingHandlerInterceptor debuggingHandlerInterceptor) {
    return new WebMvcConfigurer() {
        @Override
        public void addInterceptors(InterceptorRegistry registry) {
            registry.addInterceptor(debuggingHandlerInterceptor);
        }
    };
}

Verifying setup

In order to make sure that this setup works, we’ll write two simple tests and verify the console output

@SpringBootTest
@ExtendWith(OutputCaptureExtension.class)
@AutoConfigureMockMvc
public class TenantScopedDebugTest {

    @Autowired
    private MockMvc mockMvc;

    @Test
    void byDefaultWeWillOnlyGetInfoLogs(CapturedOutput output) throws Exception {
        mockMvc.perform(get("/api/tenants/some-tenant/action"))
                .andExpect(status().isOk());
        String out = output.getOut();
        assertThat(out).contains("Info log that we got request from tenant some-tenant");
        assertThat(out).doesNotContain("And here is some debug data for this request");
    }

    @Test
    void enableTenantDebug_willProduceLogs(CapturedOutput output) throws Exception {
        // first we need to set property that will allow debugging for specific tenant
        mockMvc.perform(post("/actuator/env").contentType(MediaType.APPLICATION_JSON)
                .content(
                        """
                                {
                                "name": "tenants-for-debugging",
                                "value": "32167"
                                }
                                """
                )).andExpect(status().isOk());

        mockMvc.perform(get("/api/tenants/32167/action"))
                .andExpect(status().isOk());
        String out = output.getOut();
        assertThat(out).contains("Info log that we got request from tenant 32167");
        assertThat(out).contains("And here is some debug data for tenant 32167");
    }

}

And this is how logs produced by running this test will look like — you can see that we’ll get 2 INFO logs and one DEBUG

2023-03-18 19:54:59.442  INFO 6684 --- [    Test worker] e.d.c.ControllerForTenantWithDebug       : Info log that we got request from tenant some-tenant
2023-03-18 19:55:04.300  INFO 6684 --- [    Test worker] e.d.c.ControllerForTenantWithDebug       : Info log that we got request from tenant 32167
2023-03-18 19:55:04.300 DEBUG 6684 --- [    Test worker] e.d.c.ControllerForTenantWithDebug       : And here is some debug data for tenant 32167

Conclusion

In this article, I have demonstrated how to configure a small Spring Boot application to allow setting the log level to DEBUG only for specific tenants by updating properties. By extending the Logback filter and creating a component that sets the MDC property, we can enable thread-local debugging in a tenant-specific manner. This approach offers a more efficient and targeted way of debugging, avoiding the need to enable debugging for the entire application or specific packages/classes.

I hope that this article provides useful insights and guidance for developers working on large-scale, multi-tenant applications and helps them optimize their debugging process.