akkinoc / logback-access-spring-boot-starter Goto Github PK

We have the actuator on a different port, e.g.

management.server.port=9000

Actuator requests are not logging.

How can we make actuator requests logs to access log?

Thank you.

I'm using version 2.4.0 in my project, and configged SizeAndTimeBasedRollingPolicy as below:

        <rollingPolicy

		class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
		<fileNamePattern>${LOG_FILE}.%d{yyyy-MM-dd}.%i</fileNamePattern>
		<MaxFileSize>10MB</MaxFileSize>
	</rollingPolicy>

Most of time it works fine, but I found it used some unexpected log filenames as shown in the picture below.
Seems it only happens when huge records generated?

I was confused as to which license this project used until I noticed the link in the readme. You should include a file called LICENSE (or LICENSE.txt, or COPYING, or COPYING.txt) with the license itself. The license also recommends adding a small header to all your files, but I think that's optional (it does help).

Edit: I should also mention that adding the license file will allow GitHub to autodetect which license you're using.

When trying to use this library on embedded Tomcat with Async enabled, I get the following error

Async support must be enabled on a servlet and for all filters involved in async request processing.

Could you add async support here?

See Also: http://docs.spring.io/spring-security/site/docs/current/reference/html/servletapi.html#servletapi-remote-user

I want to use logback.xml in addition to logback-access.xml. but I see that logback is not being picked up.

Here is my logback-access.xml.

<?xml version="1.0" encoding="UTF-8" standalone="yes"?>
<configuration debug="false" scan="false">
    <statusListener class="ch.qos.logback.core.status.OnConsoleStatusListener"/>

    <appender name="logstash-access" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="net.logstash.logback.encoder.LogstashAccessEncoder">
            <customFields>{"appname":"myWebservice"}</customFields>
            <includeCallerData>true</includeCallerData>
            <fieldNames>
                <fieldsRequestHeaders>@fields.request_headers</fieldsRequestHeaders>
                <fieldsResponseHeaders>@fields.response_headers</fieldsResponseHeaders>
                <fieldsRequestedUrl>@fields.requested_url</fieldsRequestedUrl>
                <fieldsStatusCode>@fields.status_code</fieldsStatusCode>
                <fields.status_code>statusCode</fields.status_code>
            </fieldNames>
        </encoder>
    </appender>

    <appender-ref ref="logstash-access"/>

Here is my logback.xml

<configuration>
<appender name="consoleAppender" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="net.logstash.logback.encoder.LogstashEncoder">
            <customFields>{"application":"helloWorld"}</customFields>
            <fieldNames>
                <version>data_version</version>
                <message>description</message>
            </fieldNames>
        <includeCallerData>true</includeCallerData>
        </encoder>
    </appender>
    <root level="INFO">
        <!--<appender-ref ref="jsonAppender"/>-->
        <!--<appender-ref ref ="stash"/>-->
        <appender-ref ref="consoleAppender"/>
    </root>
</configuration>

Since I am using logstash-logback-encoder, I included the dependency in pom.xml

<dependency>
            <groupId>ch.qos.logback</groupId>
            <artifactId>logback-access</artifactId>
            <version>1.1.6</version>
        </dependency>

I used sample/tomcat project in this repository to test the application. I do not see logs from logback.xml.

Only support % D, % r..... , %{XXXX}r not supported?

I have a spring boot 1.5.8 / undertow project with spring security configured and a standard spring error handler

@RestController
public class DefaultErrorController implements ErrorController {
	private static final String PATH = "/error";
...

for access logs,
using a spring @configuration to get access logs

@Bean
    public EmbeddedServletContainerFactory servletContainer() {
        UndertowEmbeddedServletContainerFactory factory = new UndertowEmbeddedServletContainerFactory();
        factory.addDeploymentInfoCustomizers(new UndertowDeploymentInfoCustomizer() {
            @Override
            public void customize(DeploymentInfo deploy) {
      
                deploy.addInitialHandlerChainWrapper(new HandlerWrapper() {
                    @Override
                    public HttpHandler wrap(HttpHandler handler) {
                        return new AccessLogHandler(handler, new JBossLoggingAccessLogReceiver(), "combined", Undertow.class.getClassLoader());
                    }
                });
            }
        });

        return factory;
    }

and then calling an endpoint with
curl http://localhost:8080/someBrokenPath

I get an access log that looks like this:

2018-06-05 12:23:39.466 INFO 10156 --- [ XNIO-2 task-1] io.undertow.accesslog : 0:0:0:0:0:0:0:1 - - [05/Jun/2018:12:23:39 +0930] "GET /someBrokenPath HTTP/1.1" 401 106 "-" "curl/7.59.0"

however
when I configure logback-access-spring-boot-starter with

<configuration>
    <statusListener class="ch.qos.logback.core.status.OnConsoleStatusListener" />
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
         <encoder>
            <pattern>common</pattern>
        </encoder>
    </appender>

    <appender-ref ref="CONSOLE" />

</configuration>

I get:
0:0:0:0:0:0:0:1 - - [05/Jun/2018:14:48:29 +0930] "GET /error HTTP/1.1" 401 106

I know I can manually modify the pattern to fix the missing status, threadname etc,

but what seems really broken is the path says "/error" and not "/someBrokenPath"

update:
actually the presence of a custom ErrorController makes no difference. but excluding the spring boot whitelabel error handler resolves the issue:
@SpringBootApplication(exclude = {ErrorMvcAutoConfiguration.class}

after that I get ... [2018-06-06T12:52:44.735+09:30] "GET /someBrokenPath HTTP/1.1" 401 71" ...

unfortunately I do need to customise this and I'm not seeing how I can without losing useful logs.

spring-boot-ext-logback-access 1.1, Spring Boot 1.3.3, Tomcat embedded 8.0.32

I'm never able to get the response length in the valve - it's always returned as -1 from the underlying Tomcat response, resulting in a dash - being printed in the access log.

However, when I use the generic Spring Boot access log valve configuration (server.tomcat.accesslog.enabled=true in application.properties), I'm getting the proper response size.

I compared that Spring Boot uses TomcatEmbeddedServletContainerFactory#addContextValves to add the valve in ServerProperties.Tomcat#customizeAccessLog and spring-boot-ext-logback-access does that with TomcatEmbeddedServletContainerFactory#addContextCustomizers. I tried patching spring-boot-ext-logback-access by applying the logic of Spring Boot - using addContextValves instead of using a TomcatContextCustomizer, but the result was the same - no response size logged.

Using one or the other - addContextValves vs. addContextCustomizers does affect the order of the valves - valves are processed first and context customizers later (see TomcatEmbeddedServletContainerFactory#configureContext), but as I said it did not matter in the end.

Am I missing something or is this indeed an issue in spring-boot-ext-logback-access?

Describe the bug

Running locally using an IDEA results in NullPointerExceptions when attempting to log.

Spring Boot Dependencies: Spring Boot Starter Parent 2.6.0 with Tomcat

logback-access.xml

<configuration>
    <statusListener class="ch.qos.logback.core.status.OnConsoleStatusListener"/>

    <appender name="logstash-access" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="net.logstash.logback.encoder.LogstashAccessEncoder">
            <fieldNames>
                <requestHeaders>request_headers</requestHeaders>
                <responseHeaders>response_headers</responseHeaders>
                <requestedUrl>requested_url</requestedUrl>
                <statusCode>status_code</statusCode>
            </fieldNames>
            <requestHeaderFilter class="a.package.LogstashHeaderFilter">
                <exclude>Authorization</exclude>
            </requestHeaderFilter>
        </encoder>
    </appender>

    <appender-ref ref="logstash-access"/>
</configuration>

Log

09:49:00,681 |-ERROR in ch.qos.logback.core.ConsoleAppender[logstash-access] - Appender [logstash-access] failed to append. java.lang.NullPointerException: <get-serverName>(...) must not be null
	at java.lang.NullPointerException: <get-serverName>(...) must not be null
	at 	at dev.akkinoc.spring.boot.logback.access.tomcat.LogbackAccessTomcatEventSource.getServerName(LogbackAccessTomcatEventSource.kt:53)
	at 	at dev.akkinoc.spring.boot.logback.access.LogbackAccessEventSource$Fixed.<init>(LogbackAccessEventSource.kt:181)
	at 	at dev.akkinoc.spring.boot.logback.access.LogbackAccessEventSource.fix(LogbackAccessEventSource.kt:156)
	at 	at dev.akkinoc.spring.boot.logback.access.LogbackAccessEvent.prepareForDeferredProcessing(LogbackAccessEvent.kt:159)

To Reproduce

• Create a default spring boot app with a hello controller

    <parent>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-parent</artifactId>
        <version>2.6.0</version>
    </parent>

• Add the logback related dependencies

        <dependency>
            <groupId>net.logstash.logback</groupId>
            <artifactId>logstash-logback-encoder</artifactId>
            <version>${logback-encoder.version}</version>
        </dependency>
        <dependency>
            <groupId>ch.qos.logback</groupId>
            <artifactId>logback-classic</artifactId>
            <version>${logback.version}</version>
        </dependency>
        <dependency>
            <groupId>dev.akkinoc.spring.boot</groupId>
            <artifactId>logback-access-spring-boot-starter</artifactId>
            <version>3.1.0</version>
        </dependency>

• Add the logback-access.xml file specified above
• Start up the application
• Hit the hello controller

Expected behavior

Normal logging behavior to continue or for documentation to be available concerning upgrading the major version.

Environment

• Version of this library used: 3.0.0 and 3.1.0
• Version of Java used: Java 11 and Java 17

Describe the problem you'd like to have solved

our apps use slf4j as facade api, and log4j2 as the implementation.
however, to enable accesslog in springboot, we have to introduce logback which causes the conflicts by slf4j binding the wrong implementation. because the both slf4j api implementation are on the JVM classpath

Describe the solution you'd like

i'd like to have the option to select the access log implementation, either log4j2 or logback

EmbeddedServletContainerCustomizer is replaced by ConfigurableServletWebServerFactory in the upcoming spring boot version so the library is not working. It would be nice to support it.

As far as I can see (may be mistaken) there is no configuration for the Logback TeeFilter.

So if you want the full request/response in your logging, for example:

logback-access.xml

<configuration>
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%fullRequest%n%n%fullResponse</pattern>
        </encoder>
    </appender>
    <appender-ref ref="CONSOLE" />
</configuration>

you will always see a blank responseContent.

This is because the AccessConstants.LB_OUTPUT_BUFFER attribute is never set by the TeeFilter.

The workaround is to manually configure a TeeFilter something like:

@Bean
public FilterRegistrationBean requestLoggingFilter() {
    FilterRegistrationBean filterRegistrationBean = new FilterRegistrationBean(new TeeFilter());
    // filterRegistrationBean.setInitParameters(...);
    return filterRegistrationBean;
}

and the request/response is logged.

Is omitting the TeeFilter auto configuration intentional or something that should be added?

i.e.

<SpringResponseHeader>
   <fieldName>X-B3-TraceId</fieldName>
   <header>TraceId</header>
</SpringResponseHeader>

At the moment this awesome starter has a dependency on spring-boot-starter-web which by default brings tomcat.

Would it make sense to make spring-boot-starter-web optional as it does with spring-boot-starter-webflux dependency?

We cannot upgrade to version 2.7.0:

[ERROR] Failed to execute goal on project test-accesslog: Could not resolve dependencies for project de.tcc:test-accesslog:jar:1.0-SNAPSHOT: Failed to collect dependencies at net.rakugakibox.spring.boot:logback-access-spring-boot-starter:jar:2.7.0: Failed to read artifact descriptor for net.rakugakibox.spring.boot:logback-access-spring-boot-starter:jar:2.7.0: Failure to find io.projectreactor:reactor-bom:pom:Bismuth-M3

The mentioned library, io.projectreactor:reactor-bom:pom:Bismuth-M3, is not accessible via maven repo.
I assume though that this is a consequential error, since org.springframework.boot:spring-boot-starter-parent:2.0.0.M3 doesn't exist in the Maven repo either.

I guess building logback-access-spring-boot-starter works because of the recently added repositories section in the POM file; but this doesn't propagate if logback-access-spring-boot-starter is simply used by another project.

I'd like to turn off access logging during testing. I trust it works, so am not testing it; it's just noise during tests. I have a logback-test.xml which sets ROOT level to WARN, but that doesn't quiet access logging so that's not it. I'm also using runtime scope in for the dependency in maven, but that's not it either. Thanks!

So this issue is either 1) documentation, or 2) enhancement.

Describe the bug

The request body is being printed out only if the content type is set to application/x-www-form-urlencoded. Otherwise, it will not be printed. Am I missing to include some extra dependencies or maybe some required configuration is missing?

To Reproduce

build.gradle:

plugins {
    id 'java'
    id 'org.springframework.boot' version '3.0.6'
    id 'io.spring.dependency-management' version '1.1.0'
}

group = 'com.example'
version = '0.0.1-SNAPSHOT'
sourceCompatibility = '17'

repositories {
    mavenCentral()
}

dependencies {
    implementation 'dev.akkinoc.spring.boot:logback-access-spring-boot-starter:4.0.0'

    implementation 'org.springframework.boot:spring-boot-starter-web'
    testImplementation 'org.springframework.boot:spring-boot-starter-test'
}

tasks.named('test') {
    useJUnitPlatform()
}

application.yml:

logging:
  level:
    web: "TRACE"
server:
  port: 8989
spring:
  mvc:
    log-request-details: true

logback-access.xml:

<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%fullRequest%n%n%fullResponse</pattern>
    </encoder>
  </appender>

  <appender-ref ref="STDOUT" />
</configuration>

For example, curl -X POST localhost:8989/api/login -H "content-type: application/x-www-form-urlencoded" -d 'username=a&password=b' works as expected, while curl -X POST localhost:8989/api/login -H "content-type: application/json" -d '{"username":"a","password":"b"}' does NOT work at all - the request body is missing.

Expected behavior

It would be nice if it worked well even for some other content types, primarily for application/json.

POST /api/login HTTP/1.1
accept: */*
content-length: 21
content-type: application/json
host: localhost:8989
user-agent: curl/8.0.1

{"username":"a","password":"b"}

or even better, formatted as:

POST /api/login HTTP/1.1
accept: */*
content-length: 21
content-type: application/json
host: localhost:8989
user-agent: curl/8.0.1

{
  "username": "a",
  "password": "b"
}

Environment

• Version of this library used: 4.0.0
• Version of Java used: 17.0.7 | 20.0.1
• Version of Spring Boot used: 3.0.6
• Web server used (Tomcat, Jetty, Undertow or Netty): Tomcat
• Web application type used (Servlet Stack or Reactive Stack): Servlet Stack

I was trying to figure out why I was not seeing any access logs, or even log messages during startup that it was reading the logback-access.xml. It appears adding an additional Tomcat connector is causing an issue.

/**
 * Configuration of the embedded Tomcat container.
 */
@Configuration
public class TomcatConfig {

    @Value("${http.port}")
    private int httpPort;

    @Bean
    public ServletWebServerFactory servletContainer() {
        TomcatServletWebServerFactory tomcat = new TomcatServletWebServerFactory();
        tomcat.addAdditionalTomcatConnectors(createStandardConnector());
        return tomcat;
    }

    private Connector createStandardConnector() {
        Connector connector = new Connector(TomcatServletWebServerFactory.DEFAULT_PROTOCOL);
        connector.setPort(httpPort);
        return connector;
    }

}

I can step through your code with this commented out, but uncommenting it and I never end up hitting any of the breakpoints, or messages to help explain why.

I am trying to use logback-access-spring-boot-starter in an existing Java-tomcat-spring-mvc based spring boot application. Since this library used kotlin, I have added kotlin dependencies and the compilation succeeded. Although getting below error after successfully started the tomcat application

java.lang.NoSuchMethodError: 'java.util.SortedMap kotlin.collections.MapsKt.sortedMapOf(java.util.Comparator, kotlin.Pair[])'
        at dev.akkinoc.spring.boot.logback.access.tomcat.LogbackAccessTomcatEventSource$requestHeaderMap$2.invoke(LogbackAccessTomcatEventSource.kt:98)
        at dev.akkinoc.spring.boot.logback.access.tomcat.LogbackAccessTomcatEventSource$requestHeaderMap$2.invoke(LogbackAccessTomcatEventSource.kt:97)
        at kotlin.UnsafeLazyImpl.getValue(Lazy.kt:81)
        at dev.akkinoc.spring.boot.logback.access.tomcat.LogbackAccessTomcatEventSource.getRequestHeaderMap(LogbackAccessTomcatEventSource.kt:97)
        at dev.akkinoc.spring.boot.logback.access.LogbackAccessEventSource$Fixed.<init>(LogbackAccessEventSource.kt:201)
        at dev.akkinoc.spring.boot.logback.access.LogbackAccessEventSource.fix(LogbackAccessEventSource.kt:156)
        at dev.akkinoc.spring.boot.logback.access.LogbackAccessEvent.prepareForDeferredProcessing(LogbackAccessEvent.kt:159)
        at net.logstash.logback.appender.AsyncDisruptorAppender.prepareForDeferredProcessing(AsyncDisruptorAppender.java:603)
        at net.logstash.logback.appender.AsyncDisruptorAppender.append(AsyncDisruptorAppender.java:492)
        at net.logstash.logback.appender.AsyncDisruptorAppender.append(AsyncDisruptorAppender.java:99)
        at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84)
        at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51)
        at ch.qos.logback.access.spi.AccessContext.callAppenders(AccessContext.java:40)
        at dev.akkinoc.spring.boot.logback.access.LogbackAccessContext.emit(LogbackAccessContext.kt:64)
        at dev.akkinoc.spring.boot.logback.access.tomcat.LogbackAccessTomcatValve.log(LogbackAccessTomcatValve.kt:75)
        at org.apache.catalina.core.AccessLogAdapter.log(AccessLogAdapter.java:48)
        at org.apache.catalina.core.StandardEngine.logAccess(StandardEngine.java:279)
        at org.apache.catalina.core.ContainerBase.logAccess(ContainerBase.java:1059)
        at org.apache.catalina.core.ContainerBase.logAccess(ContainerBase.java:1059)
        at org.apache.catalina.connector.CoyoteAdapter.log(CoyoteAdapter.java:484)
        at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:404)
        at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
        at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1590)
        at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
        at java.base/java.lang.Thread.run(Thread.java:829)

Common build.gradle file in which the kotlin and logback dependencies added

plugins {
        id 'java-library'
}

group = 'in.test'
version = '0.0.1-SNAPSHOT'
sourceCompatibility = '11'

configurations {
        compileOnly {
                extendsFrom annotationProcessor
        }
}

repositories {
    mavenCentral()
}

dependencies {
        compileOnly 'org.projectlombok:lombok:1.18.12'
        annotationProcessor 'org.projectlombok:lombok:1.18.12'
        api 'com.fasterxml.jackson.datatype:jackson-datatype-jsr310:2.9.2'
        api 'com.github.dozermapper:dozer-core:6.5.0'
        api 'com.vladmihalcea:hibernate-types-52:2.10.1'
        api 'org.springdoc:springdoc-openapi-webmvc-core:1.2.32'
        api 'org.springframework.cloud:spring-cloud-starter-sleuth:2.2.5.RELEASE'
        api 'org.springframework.cloud:spring-cloud-starter-zipkin:2.2.5.RELEASE'
        api 'net.logstash.logback:logstash-logback-encoder:7.0'
        api 'ch.qos.logback:logback-access:1.2.3'
        api 'dev.akkinoc.spring.boot:logback-access-spring-boot-starter:3.1.1'
        api 'org.jetbrains.kotlin:kotlin-stdlib-jdk8:1.6.0'
        api 'org.jetbrains.kotlin:kotlin-reflect:1.6.0'
        api 'com.fasterxml.jackson.module:jackson-module-kotlin'
        api 'com.cronutils:cron-utils:9.1.5'
        api 'org.springframework.boot:spring-boot-starter-data-jpa:2.3.4.RELEASE'
        api 'org.springframework.boot:spring-boot-starter-data-mongodb:2.3.4.RELEASE'
        implementation 'commons-lang:commons-lang:2.6'
        compileOnly 'org.springframework.boot:spring-boot-starter-data-rest:2.4.1'
        compileOnly 'org.springframework.boot:spring-boot-starter-oauth2-resource-server:2.3.4.RELEASE'
        compileOnly 'org.springframework.boot:spring-boot-starter-web:2.3.4.RELEASE'
        compileOnly 'org.springframework.cloud:spring-cloud-starter-openfeign:2.2.5.RELEASE'
}

Application's build.gradle

plugins {
        id 'java'
        id 'application'
        id 'org.springframework.boot' version '2.3.4.RELEASE'
        id 'io.spring.dependency-management' version '1.0.10.RELEASE'
}

group = 'in.test'
version = '0.0.1-SNAPSHOT'
sourceCompatibility = '11'
mainClassName = 'in.test.testservice.TestServiceApplication'

configurations {
        compileOnly {
                extendsFrom annotationProcessor
        }
}

repositories {
        mavenCentral()
        maven { url 'https://jitpack.io' }
}

ext {
        set('springCloudVersion', "Hoxton.SR8")
}

dependencies {
        compileOnly 'org.projectlombok:lombok:1.18.12'
        annotationProcessor 'org.projectlombok:lombok:1.18.12'
        implementation project (':spring-backend-common')
        implementation 'com.github.alturkovic.distributed-lock:distributed-lock-core:1.4.2'
        implementation 'org.springframework.boot:spring-boot-starter-oauth2-resource-server'
        implementation 'org.springframework.boot:spring-boot-starter-web'
        implementation 'org.springframework.boot:spring-boot-starter-actuator'
        implementation 'org.springframework.cloud:spring-cloud-starter-netflix-eureka-client'
        implementation 'org.springframework.cloud:spring-cloud-starter-netflix-hystrix'
        implementation 'org.springframework.cloud:spring-cloud-starter-openfeign'
        implementation 'org.springframework.cloud:spring-cloud-starter-config'
        testImplementation('org.springframework.boot:spring-boot-starter-test') {
                exclude group: 'org.junit.vintage', module: 'junit-vintage-engine'
                exclude group: 'org.mockito', module: 'mockito-core'
                exclude group: 'org.mockito', module: 'mockito-junit-jupiter'
        }
        testImplementation('org.mockito:mockito-core:3.6.0')
        testImplementation('org.mockito:mockito-junit-jupiter:3.6.0')
        testImplementation('org.mockito:mockito-inline:3.6.0')
        runtimeOnly 'org.postgresql:postgresql'
}

dependencyManagement {
        imports {
                mavenBom "org.springframework.cloud:spring-cloud-dependencies:${springCloudVersion}"
        }
}

test {
        useJUnitPlatform()
}

Question

Is there a way to hash the remote user that gets logged?

There used to be LogbackAccessSecurityAttributesSaveFilter which enabled to override the doFilter() function, but it has been removed in the newer version of this starter.

I am trying to send access log to syslog.

But I am getting:

ERROR in ch.qos.logback.classic.net.SyslogAppender[SYSLOG] - Appender [SYSLOG] failed to append. java.lang.ClassCastException: net.rakugakibox.spring.boot.logback.access.tomcat.TomcatLogbackAccessEvent cannot be cast to ch.qos.logback.classic.spi.ILoggingEvent

Due to the refactoring between versions 1.1 and 1.2, the thread name is not logged any more. That was handled by the Logback's default LogbackValve from which the ReconfigurableLogbackValve inherited in 1.1.

ch.qos.logback.access.tomcat.LogbackValve#invoke:

...
addThreadName(accessEvent);
...

In 1.2 the implementation was changed to utilise a new own implementation of LogbackAccessValve, but the thread name is not set anywhere.

Describe the problem you'd like to have solved

Spring Boot 3.2 just released and introduced support for Jetty 12. There were quite a few changes introduced in Jetty 12 that render this starter unusable with Spring Boot 3.2.x and the spring-boot-starter-jetty starter.

I guess there's not much you could do right now as compatibility for Jetty 12 likely also requires changes to logback-access itself.

Would it make sense to release a new version that updates the parent to Spring Boot 3.2.0 and explicitly states incompatibility with Jetty?

Hi man,
I use verison 1.6 in my Spring Boot project (Spring Boot version 1.3.3.RELEASE) and got an error:

java.lang.NoSuchMethodError: net.rakugakibox.springbootext.logback.access.tomcat.TomcatAccessEvent.setThreadName(Ljava/lang/String;)V
    at net.rakugakibox.springbootext.logback.access.tomcat.LogbackAccessValve.log(LogbackAccessValve.java:125)
    at org.apache.catalina.core.AccessLogAdapter.log(AccessLogAdapter.java:51)
    at org.apache.catalina.core.ContainerBase.logAccess(ContainerBase.java:1042)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:571)
    at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1095)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:672)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1500)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1456)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:745)

Please help me verify the issue.
Thanks.

Describe the bug

To Reproduce

Expected behavior

Environment

• Version of this library used:3.2.2
• Version of Java used:1.8

LogbackAccessContext contains following code:

    public void emit(AbstractLogbackAccessEvent event) {
        event.setUseServerPortInsteadOfLocalPort(logbackAccessProperties.isUseServerPortInsteadOfLocalPort());
        if (getFilterChainDecision(event) != FilterReply.DENY) {
            callAppenders(event);
            applicationEventPublisher.publishEvent(new LogbackAccessAppendedEvent(this, event));
        } else {
            applicationEventPublisher.publishEvent(new LogbackAccessDeniedEvent(this, event));
        }
    }

but custom filters defined in the xml like EvaluatorFilter are executed on callAppenders before the event is sent. So I always receive a LogbackAccessAppendedEvent instead of LogbackAccessDeniedEvent. Shouldn't logs that are denied by config filters be signaled as AccessDeniedEvent?
What I found is that callAppenders() evaluates internally getFilterChainDecision(eventObject) in a nested way

In the case we want to send the access logs to kibana etc. we need the logs to be in JSON format.

when i use spring boot 2.2.2.RELEASE version , it thow exception like this :

The following method did not exist:

org.springframework.boot.web.embedded.undertow.ConfigurableUndertowWebServerFactory.addDeploymentInfoCustomizers([Lorg/springframework/boot/web/embedded/undertow/UndertowDeploymentInfoCustomizer;)V

the method addDeploymentInfoCustomizers of ConfigurableUndertowWebServerFactory don't exist !

Hi,

I didn't want to setup a new logfile destination - I just wanted to log via the application's main logging subsystem.

I have quickly hacked together a bridge that logs via another logger that can be simply constructed to suit any other logging provider.

Code is here: https://gist.github.com/robshep/918c9b6eb95fd740f11891e3a2ebc9ad

The implementation that will be required can be seen in my local example:
LogbackAccessLogAdapter.java which is configured in the logback-access.xml

In my example, I log to my application's SLF4J logger using the RequestLog logger name, and I also set a filter for ignoring unwanted access log items.

The bridge itself (AccessLogToMainLogAppender.java) goes round-the-houses by using an hacked OutputStream, but that means I can continue using Pattern layout encoders etc for config simplicity.

Anyway, it might be useful to your users so feel free to point at the gist or copy it to a wiki or whatever you like.

Rob

The annotation processor does not handle javadoc tags and they are written as is in the json file. It's not a requirement for IDE to be able to parse this so the output may not be nice (I haven't tried though).

Also, please do not write "Defaults to XYZ" in the documentation since the default value is picked up by the initial value and IDEs display that information when available already. If the metadata does not contain that value the defaultValue field in manual metadata is a much better option than in the description.

Finally I understand the convenience but Optional is not supported by the annotation processor (and I am not sure the IDE is prepared to handle it). All properties are optional since the feature may not be activated (it's hard to determine this IMO). I am not convinced that storing Optional field is a good idea (though you've noticed they have to match the type of the getter/setter for the description to show up. If you have ideas to improve that, feel free to raise an issue.

Thanks!

I just ran into the issue that the access logs do not consider the attributes set by the RemoteIpValve that can be activated by setting server.use-forward-headers=true in the spring boot application.properties. After a quick search i discovered that this is because the custom LogbackAccessValve does not implement the requestAttributes functionality. Has this not be done for a specific reason? I would consider doing the work myself if there is nothing special preventing the implementation.

In the case we don't want the logs to hold the execution threads...

Easy as adding:

public class AsyncAppender extends AsyncAppenderBase<IAccessEvent> {

    private static final int CLIENT_ERROR_START = 400;
    private static final int CLIENT_ERROR_END = 599;

    @Override
    protected boolean isDiscardable(IAccessEvent event) {
        int status = event.getStatusCode();
        return status < CLIENT_ERROR_START || status > CLIENT_ERROR_END;
    }

    @Override
    protected void preprocess(IAccessEvent eventObject) {
        eventObject.prepareForDeferredProcessing();
    }


}

And in the xml file:

  <appender name="ASYNC_ACCESS" class="com.intel.swiss.micro.framework.log.logback.AsyncAppender">
    <appender-ref ref="FILE_ACCESS"/>
  </appender>

Hi!
It's common to have a load balancer or container orchestration system probing that your application is ready to serve traffic. At the moment, I'm using Janino to exclude those access logs from appearing, but I believe it's such a common issue that it would be helpful to provide a Spring property to enable/disable excluding the health check access logs.
The request uri to be excluded would be the actuator health endpoint, and only when the response is 200 OK. That way, if something goes wrong, you still see the errors. But you no longer get an infinite log full of GET /health 200 OK.

I'd be happy to contribute, but I don't know how that can be done in this library.

Add support for logback-access new pom coordinates: https://github.com/qos-ch/logback-access

  <dependency> 
    <groupId>ch.qos.logback.access</groupId>
    <artifactId>tomcat</artifactId>
    <version>2.0.0</version>      
  </dependency>

  <dependency>
    <groupId>ch.qos.logback.access</groupId>
    <artifactId>jetty11</artifactId>
    <version>2.0.0</version>
  </dependency>    

  <dependency>
    <groupId>ch.qos.logback.access</groupId>
    <artifactId>jetty12</artifactId>
    <version>2.0.0</version>
  </dependency>    

Also some package name changes.

Hi,

is it possible to use yuor solution on Wildfly (10) / JBoss (EAP 7)?
If yes - could you write short "how to" or add simple project, please?

Cheers
Mariusz

Question

The original problem

logback-access has a feature that helps avoid polluting access logs with binary file content.
This works OK for response bodies with image/* content type.
However, this does not work for:

• Request bodies (e.g. image, PDF, ZIP, etc.)
• Response bodies of any non-image content type (e.g. PDF or ZIP)

This has been reported as https://jira.qos.ch/browse/LOGBACK-1526, but there has been no action for over a year.

The workaround

In our Java project that uses 2.7.1 version of this lib, we have implemented a workaround for this in a copy of TomcatLogbackAccessEvent. The changes were minimal - you can see them in this comment.

The current problem

As the 3.x version of this lib was rewritten to Kotlin, our classloading hack naturally no longer works.

On one hand, the original problem is a Logback issue that has nothing to do with this lib, but on the other, it seems LogbackAccessTomcatEventSource.kt does not extend ch.qos.logback.access.spi.AccessEvent, so even if they fixed the issue, changes would have to be made in this lib? (I'm not fluent in Kotlin - might be misreading the code)

What options do we have?

1. Remain on 2.x version of this lib and hope LOGBACK-1526 gets resolved
2. Attempt to fix it in this lib - would something similar to the workaround we had be accepted here?
3. Any other options?

Hello,
I am using implementation group: 'dev.akkinoc.spring.boot', name: 'logback-access-spring-boot-starter', version: '3.0.0'

The below works..

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>common</pattern>
        </encoder>
    </appender>
    <appender-ref ref="console"/>
</configuration>

But the JSON logging is not printing anything in the console..

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
	<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
		<encoder class="net.logstash.logback.encoder.LogstashAccessEncoder" />
	</appender>
	<appender-ref ref="CONSOLE" />
</configuration>

Any tips ?

Describe the bug

When you configure a config file in the applicaiton.properties of springboot the file can't load.
Setting used : logback.access.config=/opt/application/logback-access.xml
you get the error :

2021-12-24 09:38:34,868 WARN o.s.b.w.s.c.AnnotationConfigServletWebServerApplicationContext - Exception encountered during context initialization - cancelling refresh attempt: org.springframework.context.ApplicationContextException: Un
able to start web server; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'tomcatServletWebServerFactory' defined in class path resource [org/springframework/boot/autoconfigure/w
eb/servlet/ServletWebServerFactoryConfiguration$EmbeddedTomcat.class]: Initialization of bean failed; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'logbackAccessTomca
tWebServerFactoryCustomizer' defined in class path resource [dev/akkinoc/spring/boot/logback/access/tomcat/LogbackAccessTomcatConfiguration.class]: Unsatisfied dependency expressed through method 'logbackAccessTomcatWebServerFactoryCusto
mizer' parameter 0; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'logbackAccessContext' defined in class path resource [dev/akkinoc/spring/boot/logback/access/LogbackAccessAut
oConfiguration.class]: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [dev.akkinoc.spring.boot.logback.access.LogbackAccessContext]: Factory m
ethod 'logbackAccessContext' threw exception; nested exception is java.io.FileNotFoundException: class path resource [opt/application/logback-access.xml] cannot be resolved to URL because it does not exist
2021-12-24 09:38:34,918 INFO o.s.b.a.l.ConditionEvaluationReportLoggingListener

To Reproduce

Create a springboot application with logback-access.xml on the file path.
create a application.properties with logback.access.config=/opt/application/logback-access.xml

Expected behavior

File load also from local and not only from the classpath

Environment

• Version of this library used:
• had this issue with all the 3.x versions of this library. The 2.x versions work correct.
• Version of Java used:
• Java 11

Describe the problem you'd like to have solved

I am currently using Micrometer Tracing and noticed that there is no traceId in the access log. I think adding this would be a great feature as it allows you to match your app log and access log entries, which can make troubleshooting easier.

Describe the solution you'd like

Open for discussion, i'd be down to contribute once we found the desired solution ^^

how to config logback-access.xml to support async appenders ?

Originally posted by @akkinoc in #38 (comment)

Any chances of getting this to work with SB3? Thanks!

Describe the bug

During a recent attack attempt on one of our services, we noticed that while Tomcat correctly rejects invalid characters in a request with a 400 Bad Request, it also forwards the request to the access logger, which itself throws a NullPointerException. This seems to be caused by the fact that any error in the tomcat parsing pipeline results in a request with a null requestURI.

Stack trace:

java.lang.NullPointerException: <get-requestURI>(...) must not be null
	at dev.akkinoc.spring.boot.logback.access.tomcat.LogbackAccessTomcatEventSource.getRequestURI(LogbackAccessTomcatEventSource.kt:85)
	at dev.akkinoc.spring.boot.logback.access.tomcat.LogbackAccessTomcatEventSource$requestURL$2.invoke(LogbackAccessTomcatEventSource.kt:94)
	at dev.akkinoc.spring.boot.logback.access.tomcat.LogbackAccessTomcatEventSource$requestURL$2.invoke(LogbackAccessTomcatEventSource.kt:93)
	at kotlin.UnsafeLazyImpl.getValue(Lazy.kt:81)
	at dev.akkinoc.spring.boot.logback.access.tomcat.LogbackAccessTomcatEventSource.getRequestURL(LogbackAccessTomcatEventSource.kt:93)
	at dev.akkinoc.spring.boot.logback.access.LogbackAccessEvent.getRequestURL(LogbackAccessEvent.kt:94)
	at ch.qos.logback.access.net.URLEvaluator.evaluate(URLEvaluator.java:47)
	at ch.qos.logback.core.filter.EvaluatorFilter.decide(EvaluatorFilter.java:65)
	at ch.qos.logback.core.spi.FilterAttachableImpl.getFilterChainDecision(FilterAttachableImpl.java:57)
	at ch.qos.logback.access.spi.AccessContext.getFilterChainDecision(AccessContext.java:95)
	at dev.akkinoc.spring.boot.logback.access.LogbackAccessContext.emit(LogbackAccessContext.kt:62)
	at dev.akkinoc.spring.boot.logback.access.tomcat.LogbackAccessTomcatValve.log(LogbackAccessTomcatValve.kt:75)

The fact that Tomcat calls the access logger on invalid requests seems to be very much intended (see documentation of Container.java#logAccess ), so the LogbackAccessTomcatEventSource should probably be able to handle null requestURIs.

To Reproduce

• Setup minimal Spring server with logback-access-spring-boot-starter
• Send a request with an invalid URL like curl 'http://localhost:8080/?a[]='
• Observe expected Tomcat error:

2022-03-17 15:38:00.605  INFO 255326 --- [nio-8080-exec-1] o.apache.coyote.http11.Http11Processor   : Error parsing HTTP request header
 Note: further occurrences of HTTP request parsing errors will be logged at DEBUG level.

java.lang.IllegalArgumentException: Invalid character found in the request target [/?a[]= ]. The valid characters are defined in RFC 7230 and RFC 3986
	at org.apache.coyote.http11.Http11InputBuffer.parseRequestLine(Http11InputBuffer.java:494)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:269)
        <snip>

• Instead of access logs, a NullPointerException can be observed in the logs:

2022-03-17 15:38:00.619 ERROR 255326 --- [nio-8080-exec-1] o.apache.coyote.http11.Http11Processor   : Error processing request

java.lang.NullPointerException: <get-requestURI>(...) must not be null
	at dev.akkinoc.spring.boot.logback.access.tomcat.LogbackAccessTomcatEventSource.getRequestURI(LogbackAccessTomcatEventSource.kt:85)
	at dev.akkinoc.spring.boot.logback.access.tomcat.LogbackAccessTomcatEventSource$requestURL$2.invoke(LogbackAccessTomcatEventSource.kt:94)
       <snip>

2022-03-17 15:38:00.619  WARN 255326 --- [nio-8080-exec-1] o.a.catalina.connector.CoyoteAdapter     : Exception while attempting to add an entry to the access log

java.lang.NullPointerException: <get-requestURI>(...) must not be null
	at dev.akkinoc.spring.boot.logback.access.tomcat.LogbackAccessTomcatEventSource.getRequestURI(LogbackAccessTomcatEventSource.kt:85)
	at dev.akkinoc.spring.boot.logback.access.tomcat.LogbackAccessTomcatEventSource$requestURL$2.invoke(LogbackAccessTomcatEventSource.kt:94)
      <snip>

Expected behavior

When an invalid request is sent to Tomcat, my expectation is that the access logger logs the parts that were successfully parsed and either does not log the invalid parts (in this case, the requestURI) or marks them as unparsable in some way.

Environment

• Version of this library used: 3.0.0
• Version of Java used: 17

Do you have any plan about supporting reactor-netty, and spring cloud gateway can work with it.