敏感词性能提升14倍优化全过程 v0.29.0

敏感词性能调优系列

v0.29.0 敏感词性能优化提升 14 倍全过程
v0.29.1 敏感词性能优化之内部类+迭代器内部类
v0.29.2 敏感词性能优化之基本类型拆箱、装箱的进一步优化的尝试
v0.29.3 敏感词性能优化之繁简体转换 opencc4j 优化
背景

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

sensitive-word-131

初步验证

自己本地用 v0.27.1 验证了一下，确实很奇怪，第一次明显很慢。
为了排除一些干扰项，我们把一些配置先关闭。
最简单的我们用 System.nanoTime 输出一下耗时，用 mills 也行。

1. public static void main(String[] args) {
2.         final List<String> allWord = Arrays.asList("敏感","最强","定制", "81", "医疗器械");
3.         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§政府单位§企业办公§仓储行业§医疗器械§教育单位§耐用品§电子产品包装§商城卖场";
5.         // 初始化敏感词库
6.         SensitiveWordBs sensitiveWordBs = SensitiveWordBs.newInstance()
7.                 .wordFailFast(true)
8.                 .wordAllow(WordAllows.empty())
9.                 .wordDeny(new IWordDeny() {
10.                     @Override
11.                     public List<String> deny() {
12.                         return allWord;
13.                     }
14.                 })
15.                 .ignoreChineseStyle(false)
16.                 .ignoreCase(false)
17.                 .ignoreEnglishStyle(false)
18.                 .ignoreNumStyle(false)
19.                 .ignoreRepeat(false)
20.                 .ignoreWidth(false)
21.                 .wordTag(WordTags.none())
22.                 .init();
24.         costTimeTest(sensitiveWordBs, demo1);
25.     }
27.     private static void costTimeTest(SensitiveWordBs sensitiveWordBs, String demo1) {
28.         int count = 5;
29.         for (int i = 0; i < count; i++) {
30.             long startTime = System.nanoTime();
31.             List<String> emitWord1 = sensitiveWordBs.findAll(demo1);
32.             long costTime = System.nanoTime() - startTime;
33.             System.out.println("cost=" + costTime);
34.         }
35.     }

复制代码

输出：

1. cost=27687800
2. cost=3623000
3. cost=2764000
4. cost=4456500
5. cost=6652700

复制代码

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

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

复制代码

排除问题

确认了问题之后，就要找到到底慢在哪里。
有一些方法：
1）每个方法加耗时日志，适用性广，但是比较麻烦。如果没有源代码的话，也无法直接修改。
2） 用 Profiling 工具更方便一些。
Java Flight Recorder (JFR)（JDK 自带，jcmd 或 jfr 启动）
VisualVM（免费 GUI，适合初步分析）
Async Profiler + 火焰图（性能瓶颈定位神器）
YourKit / JProfiler（商业工具，功能更全）
初步猜想

一些初步的猜想：

• 第一次执行，初始化加载了一些信息比较慢。
  
• 后续执行被 jvm 编译优化了，性能提升。
  
• 因为后续执行耗时明显下降，一些场景的比如 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，可以在代码里手动控制录制

1. import jdk.jfr.Recording;
2. import java.nio.file.Path;
4. public class JFRDemo {
5.     public static void main(String[] args) throws Exception {
6.         try (Recording recording = new Recording()) {
7.             recording.start();
8.             
9.             // 运行你要分析的代码
10.             MyUtil.someMethod();
11.             
12.             recording.stop();
13.             recording.dump(Path.of("app.jfr")); // 保存到文件
14.         }
15.     }
16. }

复制代码

我们略微调整

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

复制代码

执行后可以看到根目录下 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

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

复制代码

慢的点

可以看到比较慢的2个点

• String.toCharArray(): char[] 54%
  
• InnerWordFormatUtils.formatCharsMapping(String, IWordContext): Map 11%
  

优化方案

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

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

复制代码

针对2，用 char[] 数组替代肯定是最好的，但是字符比较复杂，暂时还是 map 适用性更强。
如果不指定格式转换，可以考虑 map 为空，取不到用原始值，减少这一份消耗。
InnerWordFormatUtils.formatCharsMapping(String, IWordContext): Map 优化

优化方案：新增一个针对整体字符串 format 的处理类 IWordFormatText，如果 IWordFormat 是系统默认的 none，直接返回 emptyMap
限制场景：仅针对不做任何优化的场景有作用。
内存优化：只有映射 c 和 mc 不同，才放入映射 map
实现:

1. /**
2. * 默认实现
3. *
4. * @author d
5. * @since 0.28.0
6. */
7. public class WordFormatTextDefault extends AbstractWordFormatText {
9.     @Override
10.     protected Map<Character, Character> doFormat(String text, IWordContext context) {
11.         // 单个字符串里信息
12.         final IWordFormat wordFormat = context.wordFormat();
13.         // 不需要处理的场景
14.         if(wordFormat.getClass().getName().equals(WordFormatNone.class.getName())) {
15.             return Collections.emptyMap();
16.         }
18.         Map<Character, Character> map = new HashMap<>();
19.         for(int i = 0; i < text.length(); i++) {
20.             char c = text.charAt(i);
21.             char mc = wordFormat.format(c, context);
23.             if(c != mc) {
24.                 map.put(c, mc);
25.             }
26.         }
27.         return map;
28.     }
29.    
30. }

复制代码

JFR 对比效果：JFR 为 7571
严谨起见，我们加一下额外项目的测试对比，对比5次
v0.27.1 直接运行1W次，5 次均值：7255 ，明细如下：

1. 7613
2. 7166
3. 7156
4. 7176
5. 7164

复制代码

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

1. 7650
2. 7074
3. 7002
4. 6979
5. 6992

复制代码

看来这个 cpu 火焰图和时间耗时不是严格等价。
这里只提升了 1% 左右的性能。
罢了，看在内存的面子上，我们先发布一个版本。
发布

此代码发布，放在 v0.28.0 版本。
针对 toCharArray 的改进

思路

我们尽量避免 toCharArray，使用原始的字符串 string.charAt 替代。
不过这个 charAt 有一点不太好：

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

复制代码

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

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

修改点比较多，涉及到的地方够改掉了。
遗憾的是破坏了两个带 chars 的接口，接口本身设计的不够好。
ISensitiveWordCharIgnore 和 IWordReplace
从原始的 chars->text
效果

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

1. 792
2. 456
3. 449
4. 410
5. 437

复制代码

和 v0.28.0 对比提升了多少倍呢？大概 14 倍
7139.4 ÷ 508.8 ≈ 14.03
反思

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

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

1.     public static void main(String[] args) {
2.         for(int k = 0; k < 5; k++) {
3.             // 1W 次
4.             long start = System.currentTimeMillis();
5.             for(int i = 0; i < 10000; i++) {
6.                 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§应用范围§多用于产品信息固有资产登记航空仓库管理 医疗政府机构等§"
7.                         + RandomUtil.randomString("1234567890bcdefghiJKLMNOPQRSTUVWXYZ", 100);
8.                 SensitiveWordHelper.findAll(randomText);
9.             }
10.             long end = System.currentTimeMillis();
11.             System.out.println(end-start);
12.         }
13.     }

复制代码

新代码

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

1. 2308
2. 1621
3. 1595
4. 1664
5. 1738

复制代码

v0.28.0

5 次均值：7636.4

1. 8438
2. 7463
3. 7404
4. 7436
5. 7441

复制代码

总结

这个测试文本量，效果大概提升 4 倍
文本越长，效果越显著。
查看一次耗时

说明

无论是整体跑，还是单个跑，都会发现第一次明显比较慢。
多次跑应该是 jvm 优化，我们来看一下单词的
我们回到问题的最开始，看的出来平均耗时优化了，但是初始化耗时还是这么慢。
跑5次

5 次效果如下：

1. 21
2. 1
3. 1
4. 1
5. 1

复制代码

单词跑有个问题，前面的 wordBs 初始化干扰太大，我们暂时用加耗时的方法来处理下。
第二个问题：mills 不够精确，可以用 nanoTime 替代。
我们改为 nanoTime 跑5次

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

1. 13518800
2. 2854600
3. 1836900
4. 1503900
5. 925400

复制代码

我们重点看一下第一次为什么这么慢。
子方法耗时拆分

演示一下，二分法：

1. public <R> List<R> findAll(final String target, final IWordResultHandler<R> handler) {
2. //        ArgUtil.notNull(handler, "handler");
4.         long s1 = System.nanoTime();
5.         List<IWordResult> wordResults = sensitiveWord.findAll(target, context);
6.         System.out.println(System.nanoTime()-s1);
8.         long s2 = System.nanoTime();
9.         List<R> res = CollectionUtil.toList(wordResults, new IHandler<IWordResult, R>() {
10.             @Override
11.             public R handle(IWordResult wordResult) {
12.                 return handler.handle(wordResult, context, target);
13.             }
14.         });
15.         System.out.println(System.nanoTime()-s2);
16.         return res;
17.     }

复制代码

耗时：

1. 17042800  #findAll
2. 2316800  #handle
3. 22018600  #total

复制代码

不过有一个问题，这个不太稳定。只能看比例。
很离谱的一个点：
中间只隔了下面的方法，耗时 3ms。

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

复制代码

原因

所以第一次请求，涉及到了
JVM 类和方法还没加载：第一次调用 sensitiveWord.findAll 可能会触发类加载、静态初始化。
JIT（即时编译）没起作用：第一次运行是解释执行，速度慢。
热点优化没完成：JIT 会把频繁调用的方法编译成本地代码，但需要多次调用才会触发。
解决方案

其实也不难，可以提前调预热一下。
在 init() 的时候，指定预热策略，简单的触发一下。
避免不太懂的性能测试的伙伴执着于第一次的问题。
策略支持用户自定义。
效果

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

1. 4520900
2. 2804500
3. 2493600
4. 976000
5. 1011100

复制代码

和 v0.28.0 对比

1. 20762000
2. 3903400
3. 3401200
4. 8672000
5. 7852000

复制代码

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

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

https://github.com/houbb/sensitive-word

小结

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

来源：豆瓜网用户自行投稿发布，如果侵权，请联系站长删除