Windows 11
OpenJDK 17
Spring Boot 3.1.11 and 3.2.5
logging.pattern.level work as expected in spring boot 3.1.x but not in 3.2.x
logging.pattern.level=%5p [${spring.application.name:},%X{traceId:-},%X{spanId:-}]
plugins {
id 'java'
id 'org.springframework.boot' version '3.1.11'
id 'io.spring.dependency-management' version '1.1.4'
}
group = 'com.example'
version = '0.0.1-SNAPSHOT'
java {
sourceCompatibility = '17'
}
configurations {
compileOnly {
extendsFrom annotationProcessor
}
}
repositories {
mavenCentral()
}
ext {
set('springBootAdminVersion', "3.2.3")
set('springCloudVersion', "2022.0.5")
}
dependencies {
implementation 'org.springframework.boot:spring-boot-starter-actuator'
implementation 'org.springframework.boot:spring-boot-starter-web'
// implementation 'de.codecentric:spring-boot-admin-starter-client'
implementation 'io.micrometer:micrometer-tracing-bridge-brave'
// implementation 'org.springframework.cloud:spring-cloud-starter-netflix-eureka-client'
compileOnly 'org.projectlombok:lombok'
runtimeOnly 'io.micrometer:micrometer-registry-prometheus'
annotationProcessor 'org.projectlombok:lombok'
testImplementation 'org.springframework.boot:spring-boot-starter-test'
}
dependencyManagement {
imports {
mavenBom "de.codecentric:spring-boot-admin-dependencies:${springBootAdminVersion}"
mavenBom "org.springframework.cloud:spring-cloud-dependencies:${springCloudVersion}"
}
}
tasks.named('test') {
useJUnitPlatform()
}
In Spring boot 3.1.11 the console log display normal.
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v3.1.11)
2024-05-06T16:23:33.431+08:00 INFO [spring-boot-tracelog-example,,] 14540 --- [ main] com.example.RunApplication : Starting RunApplication using Java 17.0.10 with PID 14540 (D:\developer\code\codeup\aipark\commercial-support\spring-boot-tracelog-example\build\classes\java\main started by LiuDecai in D:\developer\code\codeup\aipark\commercial-support\spring-boot-tracelog-example)
2024-05-06T16:23:33.433+08:00 INFO [spring-boot-tracelog-example,,] 14540 --- [ main] com.example.RunApplication : No active profile set, falling back to 1 default profile: "default"
2024-05-06T16:23:33.997+08:00 INFO [spring-boot-tracelog-example,,] 14540 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http)
2024-05-06T16:23:34.003+08:00 INFO [spring-boot-tracelog-example,,] 14540 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2024-05-06T16:23:34.003+08:00 INFO [spring-boot-tracelog-example,,] 14540 --- [ main] o.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/10.1.20]
2024-05-06T16:23:34.054+08:00 INFO [spring-boot-tracelog-example,,] 14540 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2024-05-06T16:23:34.054+08:00 INFO [spring-boot-tracelog-example,,] 14540 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 589 ms
2024-05-06T16:23:34.391+08:00 INFO [spring-boot-tracelog-example,,] 14540 --- [ main] o.s.b.a.e.web.EndpointLinksResolver : Exposing 1 endpoint(s) beneath base path '/actuator'
2024-05-06T16:23:34.421+08:00 INFO [spring-boot-tracelog-example,,] 14540 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path ''
2024-05-06T16:23:34.428+08:00 INFO [spring-boot-tracelog-example,,] 14540 --- [ main] com.example.RunApplication : Started RunApplication in 1.216 seconds (process running for 1.632)
2024-05-06T16:23:34.674+08:00 INFO [spring-boot-tracelog-example,,] 14540 --- [)-192.168.1.143] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet'
2024-05-06T16:23:34.674+08:00 INFO [spring-boot-tracelog-example,,] 14540 --- [)-192.168.1.143] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet'
2024-05-06T16:23:34.674+08:00 INFO [spring-boot-tracelog-example,,] 14540 --- [)-192.168.1.143] o.s.web.servlet.DispatcherServlet : Completed initialization in 0 ms
2024-05-06T16:23:38.625+08:00 INFO [spring-boot-tracelog-example,6638938a5a24e350f33077b366c716cf,f33077b366c716cf] 14540 --- [nio-8080-exec-1] com.example.RunApplication : Hello, Spring Boot!
2024-05-06T16:23:39.643+08:00 INFO [spring-boot-tracelog-example,6638938b5a9d5a9bab99ba6c9650bc63,ab99ba6c9650bc63] 14540 --- [nio-8080-exec-4] com.example.RunApplication : Hello, Spring Boot!
2024-05-06T16:23:40.335+08:00 INFO [spring-boot-tracelog-example,6638938c4a8227d81d749bce6d40f630,1d749bce6d40f630] 14540 --- [nio-8080-exec-2] com.example.RunApplication : Hello, Spring Boot!
Here is Spring boot 3.2.5 log display.
plugins {
id 'java'
id 'org.springframework.boot' version '3.2.5'
id 'io.spring.dependency-management' version '1.1.4'
}
group = 'com.example'
version = '0.0.1-SNAPSHOT'
java {
sourceCompatibility = '17'
}
configurations {
compileOnly {
extendsFrom annotationProcessor
}
}
repositories {
mavenCentral()
}
ext {
set('springBootAdminVersion', "3.2.3")
set('springCloudVersion', "2023.0.1")
}
dependencies {
implementation 'org.springframework.boot:spring-boot-starter-actuator'
implementation 'org.springframework.boot:spring-boot-starter-web'
// implementation 'de.codecentric:spring-boot-admin-starter-client'
implementation 'io.micrometer:micrometer-tracing-bridge-brave'
// implementation 'org.springframework.cloud:spring-cloud-starter-netflix-eureka-client'
compileOnly 'org.projectlombok:lombok'
runtimeOnly 'io.micrometer:micrometer-registry-prometheus'
annotationProcessor 'org.projectlombok:lombok'
testImplementation 'org.springframework.boot:spring-boot-starter-test'
}
dependencyManagement {
imports {
mavenBom "de.codecentric:spring-boot-admin-dependencies:${springBootAdminVersion}"
mavenBom "org.springframework.cloud:spring-cloud-dependencies:${springCloudVersion}"
}
}
tasks.named('test') {
useJUnitPlatform()
}
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v3.2.5)
2024-05-06T16:22:03.177+08:00 INFO [spring-boot-tracelog-example,,] 26040 --- [spring-boot-tracelog-example] [ main] [ ] com.example.RunApplication : Starting RunApplication using Java 17.0.10 with PID 26040 (D:\developer\code\codeup\aipark\commercial-support\spring-boot-tracelog-example\build\classes\java\main started by LiuDecai in D:\developer\code\codeup\aipark\commercial-support\spring-boot-tracelog-example)
2024-05-06T16:22:03.179+08:00 INFO [spring-boot-tracelog-example,,] 26040 --- [spring-boot-tracelog-example] [ main] [ ] com.example.RunApplication : No active profile set, falling back to 1 default profile: "default"
2024-05-06T16:22:03.802+08:00 INFO [spring-boot-tracelog-example,,] 26040 --- [spring-boot-tracelog-example] [ main] [ ] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port 8080 (http)
2024-05-06T16:22:03.815+08:00 INFO [spring-boot-tracelog-example,,] 26040 --- [spring-boot-tracelog-example] [ main] [ ] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2024-05-06T16:22:03.815+08:00 INFO [spring-boot-tracelog-example,,] 26040 --- [spring-boot-tracelog-example] [ main] [ ] o.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/10.1.20]
2024-05-06T16:22:03.850+08:00 INFO [spring-boot-tracelog-example,,] 26040 --- [spring-boot-tracelog-example] [ main] [ ] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2024-05-06T16:22:03.850+08:00 INFO [spring-boot-tracelog-example,,] 26040 --- [spring-boot-tracelog-example] [ main] [ ] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 642 ms
2024-05-06T16:22:04.179+08:00 INFO [spring-boot-tracelog-example,,] 26040 --- [spring-boot-tracelog-example] [ main] [ ] o.s.b.a.e.web.EndpointLinksResolver : Exposing 1 endpoint(s) beneath base path '/actuator'
2024-05-06T16:22:04.210+08:00 INFO [spring-boot-tracelog-example,,] 26040 --- [spring-boot-tracelog-example] [ main] [ ] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port 8080 (http) with context path ''
2024-05-06T16:22:04.218+08:00 INFO [spring-boot-tracelog-example,,] 26040 --- [spring-boot-tracelog-example] [ main] [ ] com.example.RunApplication : Started RunApplication in 1.244 seconds (process running for 1.573)
2024-05-06T16:22:04.319+08:00 INFO [spring-boot-tracelog-example,,] 26040 --- [spring-boot-tracelog-example] [)-192.168.1.143] [ ] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet'
2024-05-06T16:22:04.319+08:00 INFO [spring-boot-tracelog-example,,] 26040 --- [spring-boot-tracelog-example] [)-192.168.1.143] [ ] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet'
2024-05-06T16:22:04.319+08:00 INFO [spring-boot-tracelog-example,,] 26040 --- [spring-boot-tracelog-example] [)-192.168.1.143] [ ] o.s.web.servlet.DispatcherServlet : Completed initialization in 0 ms
2024-05-06T16:22:15.933+08:00 INFO [spring-boot-tracelog-example,66389337dece2c41935fc0e27b544d7f,935fc0e27b544d7f] 26040 --- [spring-boot-tracelog-example] [nio-8080-exec-1] [66389337dece2c41935fc0e27b544d7f-935fc0e27b544d7f] com.example.RunApplication : Hello, Spring Boot!
2024-05-06T16:22:26.790+08:00 INFO [spring-boot-tracelog-example,66389342da99fa82b5e33c3b5dfc96d0,b5e33c3b5dfc96d0] 26040 --- [spring-boot-tracelog-example] [nio-8080-exec-4] [66389342da99fa82b5e33c3b5dfc96d0-b5e33c3b5dfc96d0] com.example.RunApplication : Hello, Spring Boot!
2024-05-06T16:22:28.116+08:00 INFO [spring-boot-tracelog-example,66389344231eef18f6f52113a245e3b1,f6f52113a245e3b1] 26040 --- [spring-boot-tracelog-example] [nio-8080-exec-3] [66389344231eef18f6f52113a245e3b1-f6f52113a245e3b1] com.example.RunApplication : Hello, Spring Boot!
Comment From: mhalbritter
Hello,
what are you trying to achieve? If you're trying to use correlated logging (log span and trace ids), Spring Boot 3.2.x supports this out of the box: https://docs.spring.io/spring-boot/docs/current/reference/htmlsingle/#actuator.micrometer-tracing.logging
If that doesn't fix your issue, please attach a sample project which we can unzip or clone. Thanks!
Comment From: Mr-LiuDC
As shown in the screenshot, in spring boot 3.2.5 the application name, log span and trace ids are displayed repeatedly, only the logging.pattern.level in green is enough.
Comment From: mhalbritter
The duplicated application name, span id and trace id in the logs with Boot 3.2.x are happening because you set the logging pattern for the level to include them:
logging.pattern.level=%5p [${spring.application.name:},%X{traceId:-},%X{spanId:-}]
this works in Boot 3.1.x, as Boot 3.1.x has no built-in support itself for trace id and span id.
In Boot 3.2.x, this support has been added. There's a new property called logging.pattern.correlation, which contains the trace id and the span id, and which is logged by default if tracing is enabled in the application. Additionally, there's logging.include-application-name which defaults to true and adds the application name to the log.
So now there are multiple variables (logging.pattern.level and logging.pattern.correlation and logging.include-application-name) which contain the application name, trace id and span id. Hence the duplicated stuff in your screenshot.
To fix your setup in 3.2.x, remove [${spring.application.name:},%X{traceId:-},%X{spanId:-}] from logging.pattern.level and, if you need to customize trace id / span id logging, use logging.pattern.correlation.
I'm going to add something to the upgrade guide about that.