果冻的猿宇宙

在上一篇的 配置 mybatis 打印出执行的 sql 及返回的结果集 中, 说到了在 mybatis 中如何打印出执行的 sql, 但是还是遗留了一个问题, 也即是它的输出的 sql 并不是最终可执行的, 而是类似于 jdbc 那种 PrepareStatement 的形式, 参数的值是用问号代替的, 如下:

select * from user where username = ? and password = ?

虽然其参数值通常也会一起输出, 但如果我们对查询的结果有疑问, 想去数据库里自己执行看看, 就不得不自己去拼凑那些最终的 sql:

select * from user where username = 'admin' and password = '123456';

如果参数特别多的查询, 这会成为一个麻烦. 那么, 是否有方式可以直接输出最终的 sql 呢? 一种方式就是下面将要介绍的 p6spy log.

p6spy log 输出效果

先看其输出的效果:

26:33 #1607390793732 | took 7ms | statement | connection 0| url jdbc:p6spy:mysql://localhost:3306/code_sample?serverTimezone=GMT%2B8
select * from user where username = ? and password = ?
select * from user where username = 'admin' and password = '123456';
26:33 list size: 1

可以看到, 除了那种 PrepareStatement 的形式, 还有最终的 sql. 那么, 要如何去实现这样的效果呢?

另注: 这里的日志布局我启用了一种极简的风格, 只有"分钟:秒数", 具体见 配置简化开发阶段日志输出布局 的介绍.

继续阅读

在开发过程中, 经常会遇到想要看到应用所执行的 sql 这样的需求.

比如你写了一个查询的功能, 但查询出来的结果与你预期的不符合, 你想搞清楚到底哪里出了问题, 你自然需要看看所执行的 sql 语句, 必要的话甚至还要亲自拷贝到数据库里去查查.

自然, 这就要求应用要能把执行的 sql 输出出来. 以常用的 mybatis 框架为例, 来看一个最终的效果:

14:48 ==>  Preparing: select * from user where id = ? 
14:48 ==> Parameters: 1(Integer)
14:48 <==      Total: 1

另注: 这里的日志布局我启用了一种极简的风格, 只有"分钟:秒数", 具体见 配置简化开发阶段日志输出布局 的介绍.

那么, 在 mybatis 里, 这个要怎么做到呢?

继续阅读

现在的很多应用默认情况下就带了很多的日志输出, 比如下面的 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)

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

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

继续阅读

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

比如这样:

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 注解简化日志功能的引入

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

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

继续阅读

对于一个开发或运维人员而言, 当系统出现故障时, 第一步常常就是查看日志. 查看日志经常碰到的一个需求就是按关键字去搜索, 在日常开发机子上的 IDE 上, 都集成了强大的搜索功能, 但因为系统通常部署在 Linux 系统上, 一般只有命令行界面, 在其上应该怎么去搜索呢? 恐怕有些同学就不是那么清楚了.

有些人会用 ftp 之类的把日志下载下来本地再搜索, 如果是小一点的文件还好, 但日志文件往往都比较大, 因此这样的方式无疑是极为低效的.

下面就介绍一种相对快捷的方式, 也不需要用到特别高级的命令, 仅需要 tail 和 grep 两个命令结合起来即可, 能达到这样一个效果:

1. 能按关键字搜索;
2. 在显示关键字所在行时还能高亮关键字;
3. 能把关键字所在行的上下文, 比如上下 10 行的内容也一起显示出来.

下面是一个效果示意图:

在这里, 我用我云主机的 nginx access log 做了个示范, 我搜索一篇文章 url 的关键字 "a-port", 然后显示出搜索的结果及上下文, 可以看到关键字被标红显示, 上下文也有显示, 多个搜索结果间以蓝色的短横间隔开来.

下面具体说说怎么实现这样的搜索, 先具体讲讲各个命令及参数, 再说说怎么结合起来, 最后还给出一个脚本化的高级用法.

继续阅读