一句话描述

com.baomidou.mybatisplus.extension.activerecord.Model每次被实例化时，都会创建log对象，而log在市面上的众多实现在创建时很消耗CPU和内存，因此在业务繁忙时，会有严重的性能问题。

当前使用版本(必填,否则不予处理)

3.4.2 理论上此问题从3.1.2开始就存在。

该问题是如何引起的？(确定最新版也有问题再提!!!)

随便新建一个类，继承com.baomidou.mybatisplus.extension.activerecord.Model，当业务代码中频繁创建Model时，CPU使用率会飙升（相比3.1.2之前的版本）。 通过JProfiler、Arthas或jstack都可以看到CPU消耗在创建log对象上。 翻了下Commit记录，此问题应该是从3.1.2开始就存在。

重现步骤(如果有就写完整)

已写出重现的Demo，见：https://github.com/jptx1234/mp-model-test

以下测试过程均通过此Demo完成。此Demo的日志实现为Java自带的JUL。

测试环境：

Java 版本：OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.5+10, mixed mode)

CPU：Intel(R) Xeon(R) Silver 4214 CPU @ 2.20GHz 48核

内存：256G

操作系统：CentOS Linux release 7.6.1810 (Core)（最小安装）

这是台实体机，测试时，整台机器上除了CentOS安装后默认自带的服务外，没有其他服务在运行。

测试方法

mvn package
java -jar target/mp-model-test.jar

JMH运行结果（中间过程略过，截取最后的总结输出）：

Benchmark                            Mode  Cnt    Score    Error   Units
TestMain.testCreateModelWithLog     thrpt   10    3.936 ±  0.027  ops/us  -- 每微秒能创建3.9个对象（带log）
TestMain.testCreateModelWithoutLog  thrpt   10  248.022 ±  9.468  ops/us  -- 每微秒能创建248个对象（不带log）
TestMain.testCreateModelWithLog      avgt   10    0.253 ±  0.009   us/op  -- 每次创建对象消耗0.253微秒（带log）
TestMain.testCreateModelWithoutLog   avgt   10    0.004 ±  0.001   us/op  -- 每次创建对象消耗0.004微秒（不带log）

可以看出，在此测试环境中，Model类中有log会比无log慢两个数量级。

使用如下命令可以方便地观察测试时的调用占比：

java -jar target/mp-model-test.jar  -prof stack

观察到的热点方法占比（只截取了明显的一部分）：

....[Thread state: RUNNABLE]........................................................................
 46.9%  93.9% java.security.AccessController.doPrivileged
  1.6%   3.2% java.util.logging.LogManager.getLogger
  0.9%   1.9% me.jptx.mp.model.test.jmh_generated.TestMain_testCreateModelWithLog_jmhTest.testCreateModelWithLog_avgt_jmhStub
  0.2%   0.3% java.util.logging.LogManager.demandLogger
  0.2%   0.3% java.util.logging.Logger.getLogger
  0.1%   0.1% java.util.logging.LogManager$LoggerContext.ensureDefaultLogger
  0.1%   0.1% jdk.internal.misc.Unsafe.compareAndSetObject
  0.1%   0.1% java.lang.StringConcatHelper.prepend
  0.1%   0.1% java.lang.ref.ReferenceQueue.poll

可以看出，创建log的部分占用了相当多的CPU。

这里的日志实现方式是JUL，其他的日志实现方式不再测试。

其实这里的log还会大量占用内存，在我们生产环境上的log对象已经占了400M+的内存（我们项目的日志实现是Log4j2）。但由于不同的日志实现以及不同的日志配置会导致内存占用差异很大，因此这里不再测试。

MyBatis的Log会自动识别当前项目中的日志实现，但目前主流的日志框架中的Log对象都挺重的，本身设计的时候都是作为常量设计的。我能明白Model中的log是因为要获取到真实的模型类所以才在实例中创建，但目前只有一处使用，且是在有限条件下才会使用，所以我觉得可以改为懒加载。

Comment From: jptx1234

稍后我会提个PR解决此问题

Comment From: jptx1234

我们项目中的MP版本一直比较老，直到最近才升级到最新版。测试说升级之前项目占用CPU 500% - 600%，升级后能达到1500% - 1800%，分析了下原因，才发现这个问题。目前我们项目中的临时补救方案是，直接创建了个和Model类同包、同名的类，覆盖掉了Model类，在创建的这个Model类中就用的PR中的方式懒加载log，于是CPU终于降下来了。

Comment From: huayanYu

等带发版