sensitive-word 敏感词性能提升14倍优化全过程 v0.28.0 - 实践

背景

有一天，群里收到小伙伴提的一个问题，为什么程序 sensitive-word 第一次执行这么慢?

sensitive-word-131

初步验证

自己本地用 v0.27.1 验证了一下，确实很奇怪，第一次明显很慢。

为了排除一些干扰项，我们把一些配置先关闭。

最简单的我们用 System.nanoTime 输出一下耗时，用 mills 也行。

public static void main(String[] args) {
final List<
String> allWord = Arrays.asList("敏感","最强","定制", "81", "医疗器械");
String demo1 = "产品尺寸参数§60mn§50mm§210枚/包§160枚/包§名称A4银色不干胶§规格60mm*40mm 送配套模板§规格70mm*50mm 送配套模板§数量每大张21枚一包10张总计210枚§数量每大张16枚一包10张总计160枚§适用激光打印机打印油性笔书写§95mm§100mn§55mm§100枚/包§80枚/包§名称 A4银色不干胶§规格95mm*55mm 送配套模板§规格100mm*70mm 送配套模板§数量每大张10枚一包10张总计100枚§数量 每大张8枚一包10张 总计80枚§100mm§120枚/包§140枚/包§规格80mm*50mm 送配套模板§规格100mm*40mm 送配套模板§数量每大张12枚一包10张总计120枚§数量§每大张14枚包10张总计140枚§适用 激光打印机打印油性笔书写§40mm§65mm§70mm§35mm§200枚/包§240枚/包§规格70mm*40mm送配套模板§规格§65mm*35mm 送配套模板§数量 每大张20枚一包10张总计200枚§每大张24枚包10张总计240枚§适 激光打印机打印油性笔书写§适用§激光打印机打印油性笔书写§40mn§280枚/包§360枚/包§规格50mm*40mm 送配套模板§规格40mm*30mm 送配套模板§数量每大张28枚一包10张总计280枚§数量每大张36枚一包10张总计360枚§45.7mm§38.1mm§400枚/包§650枚/包§45.7mm*25.4mm送配套模板§38.1mm*21.2mm 送配套模板§每大张40枚一包10张总计400枚§数量每大张65枚一包10张总计650枚§30mm§25mr§20mm§840枚/包§1260枚/包§规格 30mm*20mm 送配套模板§规格25mm*13mm 送配套模板§数量每张84枚包10张总计840枚§数量每大张126枚一包10张总计1260枚§46mm§意制§任§1000枚/包§定§名称定制A4内割银不胶§规格46mm*11.1mm送配套模板§任意规格定制§每大张100枚包10张总计1000枚§包10张满5包送专属模板§适激光打印机打印油性笔书写§产品实拍§8格打印实拍展示(100mm*70mm)§上海荠骞文化用品固定资产标识卡§资产编号：§规格型号：§资产名称：§使用状态：§资产类别：§资产原值§存放地点§生产厂家：§使用人§备§注：§*请爱护公司财产，不要随意撕毁此标签§16格全内容打印实拍展示§固定资产标识卡§资产名称§四层货架（平板）§资产编号§3F跑菜区§规格型号§1800×500×1500§使用部门§财务部§使用时间§2019-04-26§李强§21格手写款打印展示 (60mm*40mm)§固定资标识卡§36格打印实拍展示(40mm*30mm)§固定资产标签§名称:§编号:§部门:§40格打印实拍展示(45.7mm*25.4mm)§固定资§名称：电脑§编号：20210§部门：财务部§20210201§使用人：我最强§八：找最强§编号：20210201§65格打印实拍展示(38mm*21mm)§名称：§编号：§数量：§数量:§100格打印实拍展示(46mm*11.1mm)§客服电话：159 9569 3815§: 159 9569 3815§.§客服电话：159 9569§客服电话：1599§客服电话§服电话：159 9569 3815§话：159 9569 3815§客服电话：1599569 3815§电话：159 9569 3815§9569 3815§159 9569 3815§客服电话：§低值易耗品标识牌(70mm*50mm)§购买日期§保管部门§责任人§生产厂家§不要随意撕毁此标牌*§*请爱护公司财产，不要随意撕导§品标识牌§低值易耗品标识牌§随意撕毁此标牌*§*请爱护公司财产，不要随意撕毁此标牌*§三人沙发§行政酒廊§2200*860*900§2018-07-23§应用范围§多用于产品信息固有资产登记航空仓库管理 医疗政府机构等§Mainly used for product information inherent assets registration, aviation warehouse management, medi§cal government institutions, etc§政府单位§企业办公§仓储行业§医疗器械§教育单位§耐用品§电子产品包装§商城卖场";
// 初始化敏感词库
SensitiveWordBs sensitiveWordBs = SensitiveWordBs.newInstance()
.wordFailFast(true)
.wordAllow(WordAllows.empty())
.wordDeny(new IWordDeny() {
@Override
public List<
String> deny() {
return allWord;
}
})
.ignoreChineseStyle(false)
.ignoreCase(false)
.ignoreEnglishStyle(false)
.ignoreNumStyle(false)
.ignoreRepeat(false)
.ignoreWidth(false)
.wordTag(WordTags.none())
.init();
costTimeTest(sensitiveWordBs, demo1);
}
private static void costTimeTest(SensitiveWordBs sensitiveWordBs, String demo1) {
int count = 5;
for (int i = 0; i < count; i++) {
long startTime = System.nanoTime();
List<
String> emitWord1 = sensitiveWordBs.findAll(demo1);
long costTime = System.nanoTime() - startTime;
System.out.println("cost=" + costTime);
}
}

输出：

cost=27687800
cost=3623000
cost=2764000
cost=4456500
cost=6652700

这里是纳秒，看比例也看得出第一次比较慢。

long ns = 1_000_000_000L;  // 1 秒 = 1e9 纳秒
long us = 1_000_000L;      // 1 秒 = 1e6 微秒
long ms = 1_000L;          // 1 秒 = 1e3 毫秒

排除问题

确认了问题之后，就要找到到底慢在哪里。

有一些方法：

1）每个方法加耗时日志，适用性广，但是比较麻烦。如果没有源代码的话，也无法直接修改。

2） 用 Profiling 工具更方便一些。

Java Flight Recorder (JFR)（JDK 自带，jcmd 或 jfr 启动）

VisualVM（免费 GUI，适合初步分析）

Async Profiler + 火焰图（性能瓶颈定位神器）

YourKit / JProfiler（商业工具，功能更全）

初步猜想

一些初步的猜想：

1. 第一次执行，初始化加载了一些信息比较慢。

2. 后续执行被 jvm 编译优化了，性能提升。

3. 因为后续执行耗时明显下降，一些场景的比如 IO、锁之类的可以暂时排除。

idea 中使用 profile

说明

本地使用的是 idea 免费社区版本。

IDEA Ultimate

IDEA Ultimate 自带了对 Java Flight Recorder (JFR) 的支持。启动应用时，点 Run → Profile…，选择 Java Flight Recorder。

IDEA + Async Profiler 插件

IDEA 提供了 Async Profiler 集成（从 2020.3 开始支持）。

用法：右键 Run 旁边选择 Profile with Async Profiler。

输出直接是 火焰图，更直观地看哪一层方法耗时最多。

当然，这两个方法直接用用一个不足，那就是前面的初始化信息也会被记录，有一定的干扰性。

所以需要次数多一些，比如1W次

编码 profile

JDK 11+ 提供了 jdk.jfr API，可以在代码里手动控制录制

import jdk.jfr.Recording;
import java.nio.file.Path;
public class JFRDemo
{
public static void main(String[] args) throws Exception {
try (Recording recording = new Recording()) {
recording.start();
// 运行你要分析的代码
MyUtil.someMethod();
recording.stop();
recording.dump(Path.of("app.jfr"));
// 保存到文件
}
}
}

我们略微调整

private static void costTimeTest(SensitiveWordBs sensitiveWordBs, String demo1) throws IOException {
int count = 5;
try (Recording recording = new Recording()) {
recording.start();
for (int i = 0; i < count; i++) {
long startTime = System.nanoTime();
List<
String> emitWord1 = sensitiveWordBs.findAll(demo1);
long costTime = System.nanoTime() - startTime;
System.out.println("cost=" + costTime);
}
recording.stop();
recording.dump(Path.of("app.jfr"));
// 保存到文件
}
}

执行后可以看到根目录下 app.jfr，发现这个生成 jfr 有问题。

jfr 文件如何文件如何打开分析呢？

jmc

JDK 11+ 一般自带 JMC（或者单独下载安装 JMC）

jmc 然后选择打开，发现自己的 jdk11 并没有，应该和 jvisual 一样，后续被单独拆开了。

官网下载： https://www.oracle.com/java/technologies/jdk-mission-control.html

或者 OpenJDK 社区版的 JMC： https://github.com/openjdk/jmc

下载后直接运行 JMC GUI，然后打开 .jfr 文件进行分析。

下载

可以在 https://www.oracle.com/java/technologies/javase/products-jmc9-downloads.html 页面选择合适自己的安装包。

firefox profiler

看了一下 Async Profiler 用的应该就是 https://profiler.firefox.com/ 这个页面分析文件的。

如果可以的话，你也可以直接用这个网页。

可以选择本地的 JFR 文件，或者是 URL。

整体耗时优化

1万次

这是一个循环调用 1W 次的例子，可以看到整体的耗时：

可以直接打开这个链接查看： https://share.firefox.dev/4lZljPd

整体耗时：7890ms

long time = System.currentTimeMillis();
costTimeTest(sensitiveWordBs, demo1);
long cTime = System.currentTimeMillis() - time;
System.out.println("---DONE"+cTime);

慢的点

可以看到比较慢的2个点

1. String.toCharArray(): char[] 54%

2. InnerWordFormatUtils.formatCharsMapping(String, IWordContext): Map 11%

优化方案

针对1，我们尝试优化一下，toCharArray 看 String 源码会重新创建 chars，占用内存，我们尽可能的避免。

/**
* Converts this string to a new character array.
*
* @return a newly allocated character array whose length is the length
* of this string and whose contents are initialized to contain
* the character sequence represented by this string.
*/
public char[] toCharArray() {
return isLatin1() ? StringLatin1.toChars(value)
: StringUTF16.toChars(value);
}

针对2，用 char[] 数组替代肯定是最好的，但是字符比较复杂，暂时还是 map 适用性更强。

如果不指定格式转换，可以考虑 map 为空，取不到用原始值，减少这一份消耗。

InnerWordFormatUtils.formatCharsMapping(String, IWordContext): Map 优化

优化方案：新增一个针对整体字符串 format 的处理类 IWordFormatText，如果 IWordFormat 是系统默认的 none，直接返回 emptyMap

限制场景：仅针对不做任何优化的场景有作用。

内存优化：只有映射 c 和 mc 不同，才放入映射 map

实现:

/**
* 默认实现
*
* @author d
* @since 0.28.0
*/
public class WordFormatTextDefault
extends AbstractWordFormatText {
@Override
protected Map<
Character, Character> doFormat(String text, IWordContext context) {
// 单个字符串里信息
final IWordFormat wordFormat = context.wordFormat();
// 不需要处理的场景
if(wordFormat.getClass().getName().equals(WordFormatNone.class.
getName())) {
return Collections.emptyMap();
}
Map<
Character, Character> map = new HashMap<
>();
for(int i = 0; i < text.length(); i++) {
char c = text.charAt(i);
char mc = wordFormat.format(c, context);
if(c != mc) {
map.put(c, mc);
}
}
return map;
}
}

JFR 对比效果：JFR 为 7571

严谨起见，我们加一下额外项目的测试对比，对比5次

v0.27.1 直接运行1W次，5 次均值：7255 ，明细如下：

7613
7166
7156
7176
7164

新代码直接运行1W次，均值 7139.4，明细如下：

7650
7074
7002
6979
6992

看来这个 cpu 火焰图和时间耗时不是严格等价。

这里只提升了 1% 左右的性能。

罢了，看在内存的面子上，我们先发布一个版本。

发布

此代码发布，放在 v0.28.0 版本。

针对 toCharArray 的改进

思路

我们尽量避免 toCharArray，使用原始的字符串 string.charAt 替代。

不过这个 charAt 有一点不太好：

public char charAt(int index) {
if ((index <
0) || (index >= value.length)) {
throw new StringIndexOutOfBoundsException(index);
}
return value[index];
}

如果 jdk 能提供一个直接访问的方法将完美，可惜去不得。

好处

带来的好处就是节省了 toCharArray 带来的方法+内存消耗。

修改点

修改点比较多，涉及到的地方够改掉了。

遗憾的是破坏了两个带 chars 的接口，接口本身设计的不够好。

ISensitiveWordCharIgnore 和 IWordReplace

从原始的 chars->text

效果

新代码，同样1w次循环，耗时 508.8ms，明细：

792
456
449
410
437

和 v0.28.0 对比提升了多少倍呢？大概 14 倍

7139.4 ÷ 508.8 ≈ 14.03

反思

这个大概率是每次 case 都一样，导致 jvm 优化效果很不错。

随机测试

我们来用随机，对比测试一下

测试 CASE

public static void main(String[] args) {
for(int k = 0; k <
5; k++) {
// 1W 次
long start = System.currentTimeMillis();
for(int i = 0; i <
10000; i++) {
String randomText = "产品尺寸参数§60mn§50mm§210枚/包§160枚/包§名称A4银色不干胶§规格60mm*40mm 送配套模板§规格70mm*50mm 送配套模板§数量每大张21枚一包10张总计210枚§数量每大张16枚一包10张总计160枚§适用激光打印机打印油性笔书写§95mm§100mn§55mm§100枚/包§80枚/包§名称 A4银色不干胶§规格95mm*55mm 送配套模板§规格100mm*70mm 送配套模板§数量每大张10枚一包10张总计100枚§数量 每大张8枚一包10张 总计80枚§100mm§120枚/包§140枚/包§规格80mm*50mm 送配套模板§规格100mm*40mm 送配套模板§数量每大张12枚一包10张总计120枚§数量§每大张14枚包10张总计140枚§适用 激光打印机打印油性笔书写§40mm§65mm§70mm§35mm§200枚/包§240枚/包§规格70mm*40mm送配套模板§规格§65mm*35mm 送配套模板§数量 每大张20枚一包10张总计200枚§每大张24枚包10张总计240枚§适 激光打印机打印油性笔书写§适用§激光打印机打印油性笔书写§40mn§280枚/包§360枚/包§规格50mm*40mm 送配套模板§规格40mm*30mm 送配套模板§数量每大张28枚一包10张总计280枚§数量每大张36枚一包10张总计360枚§45.7mm§38.1mm§400枚/包§650枚/包§45.7mm*25.4mm送配套模板§38.1mm*21.2mm 送配套模板§每大张40枚一包10张总计400枚§数量每大张65枚一包10张总计650枚§30mm§25mr§20mm§840枚/包§1260枚/包§规格 30mm*20mm 送配套模板§规格25mm*13mm 送配套模板§数量每张84枚包10张总计840枚§数量每大张126枚一包10张总计1260枚§46mm§意制§任§1000枚/包§定§名称定制A4内割银不胶§规格46mm*11.1mm送配套模板§任意规格定制§每大张100枚包10张总计1000枚§包10张满5包送专属模板§适激光打印机打印油性笔书写§产品实拍§8格打印实拍展示(100mm*70mm)§上海荠骞文化用品固定资产标识卡§资产编号：§规格型号：§资产名称：§使用状态：§资产类别：§资产原值§存放地点§生产厂家：§使用人§备§注：§*请爱护公司财产，不要随意撕毁此标签§16格全内容打印实拍展示§固定资产标识卡§资产名称§四层货架（平板）§资产编号§3F跑菜区§规格型号§1800×500×1500§使用部门§财务部§使用时间§2019-04-26§李强§21格手写款打印展示 (60mm*40mm)§固定资标识卡§36格打印实拍展示(40mm*30mm)§固定资产标签§名称:§编号:§部门:§40格打印实拍展示(45.7mm*25.4mm)§固定资§名称：电脑§编号：20210§部门：财务部§20210201§使用人：我最强§八：找最强§编号：20210201§65格打印实拍展示(38mm*21mm)§名称：§编号：§数量：§数量:§100格打印实拍展示(46mm*11.1mm)§客服电话：159 9569 3815§: 159 9569 3815§.§客服电话：159 9569§客服电话：1599§客服电话§服电话：159 9569 3815§话：159 9569 3815§客服电话：1599569 3815§电话：159 9569 3815§9569 3815§159 9569 3815§客服电话：§低值易耗品标识牌(70mm*50mm)§购买日期§保管部门§责任人§生产厂家§不要随意撕毁此标牌*§*请爱护公司财产，不要随意撕导§品标识牌§低值易耗品标识牌§随意撕毁此标牌*§*请爱护公司财产，不要随意撕毁此标牌*§三人沙发§行政酒廊§2200*860*900§2018-07-23§应用范围§多用于产品信息固有资产登记航空仓库管理 医疗政府机构等§"
+ RandomUtil.randomString("1234567890bcdefghiJKLMNOPQRSTUVWXYZ", 100);
SensitiveWordHelper.findAll(randomText);
}
long end = System.currentTimeMillis();
System.out.println(end-start);
}
}

新代码

实际测试发现这个在文本长的时候，效果更显著。应该是 toCharArray 的代价更高

5次均值 1785.2：

2308
1621
1595
1664
1738

v0.28.0

5 次均值：7636.4

8438
7463
7404
7436
7441

总结

这个测试文本量，效果大概提升 4 倍

文本越长，效果越显著。

查看一次耗时

说明

无论是整体跑，还是单个跑，都会发现第一次明显比较慢。

多次跑应该是 jvm 优化，我们来看一下单词的

我们回到问题的最开始，看的出来平均耗时优化了，但是初始化耗时还是这么慢。

跑5次

5 次效果如下：

21
1
1
1
1

单词跑有个问题，前面的 wordBs 初始化干扰太大，我们暂时用加耗时的方法来处理下。

第二个问题：mills 不够精确，可以用 nanoTime 替代。

我们改为 nanoTime 跑5次

看起来 ms 差不多，实际上还是差很多的。

13518800
2854600
1836900
1503900
925400

我们重点看一下第一次为什么这么慢。

子方法耗时拆分

演示一下，二分法：

public <
R> List<
R> findAll(final String target, final IWordResultHandler<
R> handler) {
// ArgUtil.notNull(handler, "handler");
long s1 = System.nanoTime();
List<
IWordResult> wordResults = sensitiveWord.findAll(target, context);
System.out.println(System.nanoTime()-s1);
long s2 = System.nanoTime();
List<
R> res = CollectionUtil.toList(wordResults, new IHandler<
IWordResult, R>() {
@Override
public R handle(IWordResult wordResult) {
return handler.handle(wordResult, context, target);
}
});
System.out.println(System.nanoTime()-s2);
return res;
}

耗时：

17042800  #findAll
2316800  #handle
22018600  #total

不过有一个问题，这个不太稳定。只能看比例。

很离谱的一个点：

中间只隔了下面的方法，耗时 3ms。

public List<
String> findAll(final String target) {
return findAll(target, WordResultHandlers.word());
}

原因

所以第一次请求，涉及到了

JVM 类和方法还没加载：第一次调用 sensitiveWord.findAll 可能会触发类加载、静态初始化。

JIT（即时编译）没起作用：第一次运行是解释执行，速度慢。

热点优化没完成：JIT 会把频繁调用的方法编译成本地代码，但需要多次调用才会触发。

解决方案

其实也不难，可以提前调预热一下。

在 init() 的时候，指定预热策略，简单的触发一下。

避免不太懂的性能测试的伙伴执着于第一次的问题。

策略支持用户自定义。

效果

优化后的效果，还是会有一些，不过可以接受。

4520900
2804500
2493600
976000
1011100

和 v0.28.0 对比

20762000
3903400
3401200
8672000
7852000

第一次峰值从 20ms=>5ms 左右。

反思

jvm 的内置优化过于强求暂时意义不大，还是推荐性能压测先做预热。

小结

性能优化是一个支持以恒的过程，每次的改动都可能会导致性能有所影响。

这个系列后续更新了几个版本，感兴趣的小伙伴可以看一下：

v0.28.0+v0.29.0 敏感词性能优化值本地方法调用为何这么慢?

v0.29.1 敏感词性能优化-0.29.1-内部类+迭代器内部类

v0.29.2 基本类型拆箱、装箱的进一步优化的尝试

v0.29.3 依赖的繁简体转换 opencc4j 优化