配置简化开发阶段日志输出布局

介绍了如何通过简化配置以解决开发阶段日志输出布局过长导致的不易查看的问题, 提供了一种极简的配置及一种适中的配置.

现在的很多应用默认情况下就带了很多的日志输出, 比如下面的 java spring-boot 框架启动时的日志:

{spring.web.resources.chain.cache=false, spring.web.resources.cache.period=0}

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v2.4.0)

2020-11-28 10:54:18.418  INFO 16144 --- [  restartedMain] n.x.sample.boot.basicweb.AppApplication  : Starting AppApplication using Java 11.0.8 on DESKTOP-CGD1N1Q with PID 16144 (C:\dev\proj\my\code-sample\be\java\fw\spring-boot\basic-web\target\classes started by xiaog in C:\dev\proj\my\code-sample\be\java\fw\spring-boot\basic-web)
2020-11-28 10:54:18.423  INFO 16144 --- [  restartedMain] n.x.sample.boot.basicweb.AppApplication  : No active profile set, falling back to default profiles: default
2020-11-28 10:54:18.453  INFO 16144 --- [  restartedMain] .e.DevToolsPropertyDefaultsPostProcessor : Devtools property defaults active! Set 'spring.devtools.add-properties' to 'false' to disable
2020-11-28 10:54:18.453  INFO 16144 --- [  restartedMain] .e.DevToolsPropertyDefaultsPostProcessor : For additional web related logging consider setting the 'logging.level.web' property to 'DEBUG'
2020-11-28 10:54:19.024  INFO 16144 --- [  restartedMain] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2020-11-28 10:54:19.031  INFO 16144 --- [  restartedMain] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2020-11-28 10:54:19.032  INFO 16144 --- [  restartedMain] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.39]
2020-11-28 10:54:19.096  INFO 16144 --- [  restartedMain] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2020-11-28 10:54:19.098  INFO 16144 --- [  restartedMain] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 644 ms
2020-11-28 10:54:19.208  INFO 16144 --- [  restartedMain] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2020-11-28 10:54:19.254  INFO 16144 --- [  restartedMain] o.s.b.a.w.s.WelcomePageHandlerMapping    : Adding welcome page: class path resource [static/index.html]
2020-11-28 10:54:19.314  INFO 16144 --- [  restartedMain] o.s.b.d.a.OptionalLiveReloadServer       : LiveReload server is running on port 35729
2020-11-28 10:54:19.337  INFO 16144 --- [  restartedMain] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2020-11-28 10:54:19.346  INFO 16144 --- [  restartedMain] n.x.sample.boot.basicweb.AppApplication  : Started AppApplication in 1.216 seconds (JVM running for 1.887)

日志信息非常丰富当然是有助于我们理解应用运行的各个方面, 但经常地, 我们也不难发现一些不方便的地方, 比如就以上述的输出为例, 前面一大堆的 布局(layout) 相关的输出就极为冗长, 而真正关心的信息却被挤在了后面, 如果你的显示屏不够宽, 这些关键的信息常常反而看不到, 需要横向滚动, 非常繁琐.

下面将介绍一种极简的日志布局方案, 如下所示:

{spring.web.resources.chain.cache=false, spring.web.resources.cache.period=0}

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v2.4.0)

49:20 Starting AppApplication using Java 11.0.8 on DESKTOP-CGD1N1Q with PID 11800 (C:\dev\proj\my\code-sample\be\java\fw\spring-boot\basic-web\target\classes started by xiaog in C:\dev\proj\my\code-sample\be\java\fw\spring-boot\basic-web)
49:20 No active profile set, falling back to default profiles: default
49:20 Devtools property defaults active! Set 'spring.devtools.add-properties' to 'false' to disable
49:20 For additional web related logging consider setting the 'logging.level.web' property to 'DEBUG'
49:20 Tomcat initialized with port(s): 8080 (http)
49:21 Starting service [Tomcat]
49:21 Starting Servlet engine: [Apache Tomcat/9.0.39]
49:21 Initializing Spring embedded WebApplicationContext
49:21 Root WebApplicationContext: initialization completed in 636 ms
49:21 Initializing ExecutorService 'applicationTaskExecutor'
49:21 Adding welcome page: class path resource [static/index.html]
49:21 LiveReload server is running on port 35729
49:21 Tomcat started on port(s): 8080 (http) with context path ''
49:21 Started AppApplication in 1.219 seconds (JVM running for 1.945)

可以看到, 仅仅输出了一个时间(分别是分钟数和秒数, 小时, 毫秒什么的都省略了), 然后就是关键的日志信息, 非常简洁, 一目了然, 基本不需要各种拓宽或横向拖动来显示.

下面说说怎么配置以达到上述效果.

继续阅读

使用 log 占位符便利日志输出

介绍了如何使用日志的占位符来简化日志字符串的拼接输出

在开发活动中, 记日志是一个很常见的操作. 记日志经常涉及到拼接字符串, 因为我们常常需要把参数的值输出出来, 同时拼上字样的提示, 这样后续查看时才好知道发生了什么.

比如这样:

package net.xiaogd.sample.mybatis.controller;

import lombok.extern.slf4j.Slf4j;
import net.xiaogd.sample.mybatis.entity.User;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.ModelAttribute;
import org.springframework.web.bind.annotation.RestController;

@Slf4j
@RestController
public class LogController {

	@GetMapping("/hello")
	public String hello(@ModelAttribute User user) {
		log.info("username: " + user.getUsername() + " , age: " + user.getAge());
		return "hello there";
	}
}

注: 如果对这里 @Slf4j 式注入 log 变量的写法有疑问, 请参考: 使用 lombok @Slf4j 注解简化日志功能的引入

这样的方式一旦参数多了, 就会显得很凌乱, 写起来也不方便, 看上去也是支离破碎的.

很多人可能因此就不去记日志了, 或者只记很少的变量的值, 给后续的排查问题就带来了麻烦.

继续阅读