RequestContextExportingAppender has a dependency on Flags which partially breaks logging

[KarboniteKream]

When Armeria is configured with Logback and RequestContextExportingAppender with custom headers, and when multiple Netty versions are present in the classpath, logs for Flags will be missing.

When the following appender with a custom header is configured in Logback:

<appender name="ARMERIA_KAFKA" class="com.linecorp.armeria.common.logback.RequestContextExportingAppender">
  <appender-ref ref="KAFKA" />
  <export>req.headers.x-real-ip</export>
</appender>

The Logback setup flow will behave as follows:

1. setExport() is called for req.headers.x-real-ip
2. Eventually, we call ExportGroupBuilder.requestHeader()
3. Following toHeaderName(), we reach this call to Flags.validateHeaders()
4. This initializes the Flags class, which initializes TransportType, which initializes TransportTypeProvider
5. Flags will log the values of all flags, and TransportTypeProvider will validate Netty versions and log a warning in case of inconsistencies

However, since we're still setting up Logback, no appenders are configured on ROOT level, so this information will never be logged.

By removing <export>req.headers.x-real-ip</export> or using req.headers.user-agent (a known and pre-cached header), the call to Flags.validateHeaders() never happens, and the Flags class is initialized after Logback setup is done. In that case, the logs will appear as expected.

We can probably fix this by breaking the dependency between RequestContextExportingAppender and `Flags.

[jrhee17]

I haven't been able to analyze the issue in detail, but perhaps we can consider a lazy loading mechanism for each flag value. We have already had multiple issues stemming from cyclic dependency when the Flags class is loaded, so I feel like we may want to take a more general approach

boolean VERBOSE_SOCKET_EXCEPTIONS

to

Supplier<Boolean> VERBOSE_SOCKET_EXCEPTIONS

The downside would be we won't be able to print flag values on initialization. Perhaps we can display this information somewhere else (i.e. DocService) instead.

[ikhoon]

I tried to make a simple reproducer but failed. It was tricky to align the initialization of the order of Flags and RequestContextExportingAppender. @KarboniteKream Could you provide an example for the problem?

I guess we can keep logging events in RequestContextExportingAppender if no appenders are configured. Afterward, the events may be emitted as an appended is added or start() is called.

[KarboniteKream]

I've created a branch for armeria-examples/spring-boot-webflux with logback-spring.xml that reproduces the issue:
KarboniteKream/armeria-examples@18c834c

If you run it as is, you'll only see 3 logs from Flags:

com.linecorp.armeria.common.Flags        : useOpenSsl: true (default)
com.linecorp.armeria.common.Flags        : Using OpenSSL: BoringSSL, 0x1010107f
com.linecorp.armeria.common.Flags        : dumpOpenSslInfo: false (default)

If the line <export>req.headers.fake-header</export> is removed or replaced with a well-known header, you'll see all logs for Flags (~70 lines):

com.linecorp.armeria.common.Flags        : verboseExceptionSampler: ExceptionSampler{rate-limit=10} (default)
com.linecorp.armeria.common.Flags        : verboseExceptions: rate-limit=10 (default)
com.linecorp.armeria.common.Flags        : preferredIpV4Addresses: * (default)
com.linecorp.armeria.common.Flags        : verboseSocketExceptions: false (default)
...

[ikhoon]

Many thanks for the reproducer. 🙇‍♂️

[ikhoon]

The problem was produced with Spring WebFlux module. But Spring MVC didn't have the same issue.
The problem was reproduced by starting main method but failed to reproduce with SpringBootTest
Let me send a patch for that soon.