HTTP传输接收服务的一次CPU占比100%排查_http-nio-8663-e占用cpu

笔者有个HTTP数据接收的项目上线，接收了大量的客户端HTTP请求，部署在三台LINUX 服务器上。

linux服务器64G内存，操作系统为CENT OS7.6

WEB容器采用TOMCAT9.0，服务端程序使用JAVA 开发，JDK版本为1.8，负责接收客户端持续不断的JSON请求，服务端将JSON解析为JAVA对象，并对每个对象的属性作合法性验证（比如，某个属性必须是16位的数字和字母且允许|间隔等待）以及相关性验证（比如 某个值必须等于A+B+C）。

上线几日来，每天接收80万的基本流水以及800万条的扩展流水。

上线首日，客户端（发送HTTP请求）报告有大量的连接超时（每次请求达到几十秒才能完成，正常时至多几十毫秒一次请求即可得到服务器200的响应）。

登录到服务端服务器排查：

在控制台命令行输入 top -c 命令，目的是显示进程运行信息列表，在屏幕显示中找到CPU占比最高的进程。

比如，最耗CPU的进程是PID为10165的进程，将ID记录下来。

在控制台命令行输入top -Hp 10165 ，显示一个进程的线程运行信息列表。

进程10165内，最耗CPU的线程PID为10604。

在控制台输入 printf “%x” 10604 将线程ID转换为16进制 ，比如 296c。

在控制台输入  jstack 10165|grep 296c -A 30   用于显示该线程的代码堆栈：

[root@localhost qf]# jstack 10165|grep 296c-A 30
"http-nio-9088-exec-43" #81 daemon prio=5 os_prio=0 tid=0x00007f36f8040800 nid=0x296c runnable [0x00007f37344bf000]
   java.lang.Thread.State: RUNNABLE
    at java.util.regex.Pattern$CharProperty.match(Pattern.java:3790)
    at java.util.regex.Pattern$Curly.match0(Pattern.java:4264)
    at java.util.regex.Pattern$Curly.match(Pattern.java:4248)
    at java.util.regex.Pattern$GroupHead.match(Pattern.java:4672)
    at java.util.regex.Pattern$GroupHead.match(Pattern.java:4672)
    at java.util.regex.Pattern$Loop.match(Pattern.java:4799)
    at java.util.regex.Pattern$GroupTail.match(Pattern.java:4731)
    at java.util.regex.Pattern$Branch.match(Pattern.java:4616)
    at java.util.regex.Pattern$GroupTail.match(Pattern.java:4731)
    at java.util.regex.Pattern$Curly.match0(Pattern.java:4286)
    at java.util.regex.Pattern$Curly.match(Pattern.java:4248)
    at java.util.regex.Pattern$GroupHead.match(Pattern.java:4672)
    at java.util.regex.Pattern$GroupHead.match(Pattern.java:4672)
    at java.util.regex.Pattern$Loop.match(Pattern.java:4799)
    at java.util.regex.Pattern$GroupTail.match(Pattern.java:4731)
    at java.util.regex.Pattern$Branch.match(Pattern.java:4616)
    at java.util.regex.Pattern$GroupTail.match(Pattern.java:4731)
    at java.util.regex.Pattern$Curly.match0(Pattern.java:4286)
    at java.util.regex.Pattern$Curly.match(Pattern.java:4248)
    at java.util.regex.Pattern$GroupHead.match(Pattern.java:4672)
    at java.util.regex.Pattern$GroupHead.match(Pattern.java:4672)
    at java.util.regex.Pattern$Loop.match(Pattern.java:4799)
    at java.util.regex.Pattern$GroupTail.match(Pattern.java:4731)
    at java.util.regex.Pattern$BranchConn.match(Pattern.java:4582)
    at java.util.regex.Pattern$GroupTail.match(Pattern.java:4731)
    at java.util.regex.Pattern$BmpCharProperty.match(Pattern.java:3812)
    at java.util.regex.Pattern$GroupHead.match(Pattern.java:4672)
    at java.util.regex.Pattern$Branch.match(Pattern.java:4618)
    at java.util.regex.Pattern$GroupTail.match(Pattern.java:4731)

 

 

 由上述可看到线程在执行正则表达式验证时发生了疑似死循环（因为该线程占用了大量的消耗时间，没有释放连接，且堆栈信息一直停顿在此处代码）。

打开ECLIPSE项目，在源代码中排查正则表达式：

import java.util.regex.Pattern;

 

 //版本号组合（验证 ）
    public final static String INTERVAL_RATEVERSION_MULTIPROVINCE_REG_EXPRESS=
                "^(((11|12|13|14|15|21|22|23|31|32|33|34|35|36|37|41|42|43|44|45|50|51|52|53|61|62|63|64|65)\\d{8}\\d{3})+(\\|((11|12|13|14|15|21|22|23|31|32|33|34|35|36|37|41|42|43|44|45|50|51|52|53|61|62|63|64|65)\\d{8}\\d{3})+))+(,(((11|12|13|14|15|21|22|23|31|32|33|34|35|36|37|41|42|43|44|45|50|51|52|53|61|62|63|64|65)\\d{8}\\d{3})+(\\|((11|12|13|14|15|21|22|23|31|32|33|34|35|36|37|41|42|43|44|45|50|51|52|53|61|62|63|64|65)\\d{8}\\d{3})+))+)*$";

...

...

//私有方法：正则表达式匹配

private void _toCheckValueFormatByRegExpress(FieldsValidatorEnums fieldsValidatorEnum, Object fieldValue) {
        if(StringUtils.isNotBlank(fieldsValidatorEnum.getRegExpress())) {
            boolean isWrong = (!fieldValue.toString().matches(fieldsValidatorEnum.getRegExpress()));//正则校验
            if (isWrong) {
                this.tipInfo += fieldsValidatorEnum.getTipForCheck(fieldValue);// 
            }
            this.validateResult = this.validateResult || (isWrong);
        }
    }

经单元测试，发现上述正则表达式在匹配验证时程序进入了死循环。

经改造，将java自带的正则替换为Google的正则

import com.google.re2j.Pattern;

将正则匹配的私有方法，改写为：

    public static boolean patternMatch(String regex, String source ) {
        if (StringUtils.isBlank(regex) || source == null) {
            
            return false;
        }

        String matchId = null;
        if (log != null && log.isDebugEnabled()) {
            matchId = UUID.randomUUID().toString().replaceAll("-", "");
        
        }

        Pattern pattern = patternMap.computeIfAbsent(regex, Pattern::compile);
        boolean  b = pattern.matches(source);
      
        return b;
    }

 经测试，执行归于正常，再次上线，HTTP延时消失，CPU占比不再冒高。