logo头像

小时候，哭是我们解决问题的绝招。长大后，笑是我们面对现实的武器。

使用正则引发的血案

后端 2018/09/01

本文于 1289 天之前发表，文中内容可能已经过时。

正则表达式

正则表达式, 一个十分古老而又强大的文本处理工具, 仅仅用一段非常简短的表达式语句, 便能够快速实现一个非常复杂的业务逻辑. 熟练地掌握正则表达式的话, 能够使你的开发效率得到极大的提升.

对于一些简单的表单式语句我们可以自己编写, 但是复杂一些并且通用的表达式我们往往会从网上直接拷贝来用. 经过大部分人实践过的一般不会出现问题, 但是偶尔也会踩坑. 最近我就在这个上面掉进了深坑.

案发

最近产线上的一个服务连续两天出现问题, 现象就是访问出现 “502 Bad Gateway” 错误. 这个服务是部署在Tomcat下的, 字面上理解就是网关出现问题了, 第一次出现问题后为了紧急修复就直接重启了服务器, 重启后就正常了. 这次事故就这样草草收场，没有留下任何有用的日志信息用来分析, 就没有继续追查下去了.

偷懒是会受到惩罚的. 果不其然, 第二天问题继续出现, 并且还引起了其他的故障. 有了前车之鉴, 这一次受到了足够重视. 为了尽快恢复服务, 重启了部分节点用来恢复产线服务. 留了一个故障节点来断案.

断案

排查思路

  1. 系统本身代码有问题, 如果是这样, 通过查看日志应该能发现集中的日志. 但是却没有, 初步排除代码逻辑处理错误
  2. 内部下游系统的问题导致的雪崩效应, 我们联系了内部下游系统观察了他们的监控，发现一起正常。可以排除下游系统故障对我们的影响
  3. 机器本身的问题, 查看机器监控, 排除机器故障问题。

即通过上述方法没有直接定位到问题。

解决方案

之前为了快速恢复服务, 我们留下了一个故障节点, 从产线上摘除, 重启了其他节点恢复服务.

下面通过jstack来分析故障

  1. 查看当前Tomcat线程pid

    1
    2
    [root@xxx ~]# ps -ef | grep tomcat
    root       142     1  0 Aug20 ?        02:46:26 /usr/local/jdk/jre/bin/java -Djava.util.logging.config.file=/usr/local/tomcat_xxx/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/tmp/tomcat_xxx/ -server -Xmx512m -Xms512m -XX:NewSize=64m -XX:MaxNewSize=128m -Djava.library.path=/usr/local/apr/lib -Dsun.lang.ClassLoader.allowArraySyntax=true -Djava.net.preferIPv4Stack=true -XX:PermSize=64M -XX:MaxPermSize=378m -Dcom.sun.management.jmxremote.authenticate=false -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.port=7080 -Dcom.sun.management.jmxremote -classpath /usr/local/tomcat_igoal/bin/bootstrap.jar -Dcatalina.base=/usr/local/tomcat_igoal -Dcatalina.home=/usr/local/tomcat_igoal -Djava.io.tmpdir=/usr/local/tomcat_igoal/temp org.apache.catalina.startup.Bootstrap start

  2. 打印jstack日志

    1
    [root@xxx ~]# jstack -l 142 > /tmp/jstack.txt

jstack.txt 文件中的内容很多， 根据关键字(程序中的包名或者类名 等) 找到匹配的内容分析线程状态

如何分析线程状态，可以查看我博客中的一篇文章 Thread State

我通过查找 ‘xxx’ 关键字找到很多内容， 但是有些是正常的，就直接过滤掉。最后找到这样一段内容，发现jstack日志中大量重复出现

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
"http-192.168.0.185-12491-600" #4971 daemon prio=5 os_prio=0 tid=0x00007f59a0334000 nid=0x1e7e runnable [0x00007f58c7ffc000]
   java.lang.Thread.State: RUNNABLE
	at java.util.regex.Pattern$5.isSatisfiedBy(Pattern.java:5251)
	at java.util.regex.Pattern$5.isSatisfiedBy(Pattern.java:5251)
	at java.util.regex.Pattern$CharProperty.match(Pattern.java:3776)
	at java.util.regex.Pattern$Curly.match(Pattern.java:4227)
	at java.util.regex.Pattern$GroupHead.match(Pattern.java:4658)
	at java.util.regex.Pattern$Loop.match(Pattern.java:4785)
	at java.util.regex.Pattern$GroupTail.match(Pattern.java:4717)
	at java.util.regex.Pattern$Ques.match(Pattern.java:4182)
	at java.util.regex.Pattern$Curly.match0(Pattern.java:4272)
	at java.util.regex.Pattern$Curly.match(Pattern.java:4234)
	at java.util.regex.Pattern$GroupHead.match(Pattern.java:4658)
	at java.util.regex.Pattern$Loop.match(Pattern.java:4785)
	at java.util.regex.Pattern$GroupTail.match(Pattern.java:4717)
	at java.util.regex.Pattern$Ques.match(Pattern.java:4182)
	at java.util.regex.Pattern$Curly.match0(Pattern.java:4272)
	at java.util.regex.Pattern$Curly.match(Pattern.java:4234)
	at java.util.regex.Pattern$GroupHead.match(Pattern.java:4658)
	at java.util.regex.Pattern$Loop.match(Pattern.java:4785)
	at java.util.regex.Pattern$GroupTail.match(Pattern.java:4717)
	at java.util.regex.Pattern$Ques.match(Pattern.java:4182)
	at java.util.regex.Pattern$Curly.match0(Pattern.java:4272)
	at java.util.regex.Pattern$Curly.match(Pattern.java:4234)
	at java.util.regex.Pattern$GroupHead.match(Pattern.java:4658)
	at java.util.regex.Pattern$Loop.match(Pattern.java:4785)
	at java.util.regex.Pattern$GroupTail.match(Pattern.java:4717)
	at java.util.regex.Pattern$Ques.match(Pattern.java:4182)
	at java.util.regex.Pattern$Curly.match0(Pattern.java:4272)
	at java.util.regex.Pattern$Curly.match(Pattern.java:4234)
	at java.util.regex.Pattern$GroupHead.match(Pattern.java:4658)
	at java.util.regex.Pattern$Loop.match(Pattern.java:4785)
	at java.util.regex.Pattern$GroupTail.match(Pattern.java:4717)
	at java.util.regex.Pattern$Ques.match(Pattern.java:4182)
	at java.util.regex.Pattern$Curly.match0(Pattern.java:4272)
	at java.util.regex.Pattern$Curly.match(Pattern.java:4234)
	at java.util.regex.Pattern$GroupHead.match(Pattern.java:4658)
	at java.util.regex.Pattern$Loop.match(Pattern.java:4785)
	at java.util.regex.Pattern$GroupTail.match(Pattern.java:4717)
	at java.util.regex.Pattern$Ques.match(Pattern.java:4182)
	at java.util.regex.Pattern$Curly.match0(Pattern.java:4272)
	at java.util.regex.Pattern$Curly.match(Pattern.java:4234)
	at java.util.regex.Pattern$GroupHead.match(Pattern.java:4658)
	at java.util.regex.Pattern$Loop.match(Pattern.java:4785)
	at java.util.regex.Pattern$GroupTail.match(Pattern.java:4717)
	at java.util.regex.Pattern$Ques.match(Pattern.java:4182)
	at java.util.regex.Pattern$Curly.match0(Pattern.java:4272)
	at java.util.regex.Pattern$Curly.match(Pattern.java:4234)
	at java.util.regex.Pattern$GroupHead.match(Pattern.java:4658)
	at java.util.regex.Pattern$Loop.match(Pattern.java:4785)
	at java.util.regex.Pattern$GroupTail.match(Pattern.java:4717)
	at java.util.regex.Pattern$Ques.match(Pattern.java:4182)
	at java.util.regex.Pattern$Curly.match0(Pattern.java:4272)
	at java.util.regex.Pattern$Curly.match(Pattern.java:4234)
	at java.util.regex.Pattern$GroupHead.match(Pattern.java:4658)
	at java.util.regex.Pattern$Loop.match(Pattern.java:4785)
	at java.util.regex.Pattern$GroupTail.match(Pattern.java:4717)
	at java.util.regex.Pattern$Ques.match(Pattern.java:4182)
	at java.util.regex.Pattern$Curly.match0(Pattern.java:4272)
	at java.util.regex.Pattern$Curly.match(Pattern.java:4234)
	at java.util.regex.Pattern$GroupHead.match(Pattern.java:4658)
	at java.util.regex.Pattern$Loop.match(Pattern.java:4785)
	at java.util.regex.Pattern$GroupTail.match(Pattern.java:4717)
	at java.util.regex.Pattern$Ques.match(Pattern.java:4182)
	at java.util.regex.Pattern$Curly.match0(Pattern.java:4272)
	at java.util.regex.Pattern$Curly.match(Pattern.java:4234)
	at java.util.regex.Pattern$GroupHead.match(Pattern.java:4658)
	at java.util.regex.Pattern$Loop.match(Pattern.java:4785)
	at java.util.regex.Pattern$GroupTail.match(Pattern.java:4717)
	at java.util.regex.Pattern$Ques.match(Pattern.java:4182)
	at java.util.regex.Pattern$Curly.match0(Pattern.java:4272)
	at java.util.regex.Pattern$Curly.match(Pattern.java:4234)
	at java.util.regex.Pattern$GroupHead.match(Pattern.java:4658)
	at java.util.regex.Pattern$Loop.match(Pattern.java:4785)
	at java.util.regex.Pattern$GroupTail.match(Pattern.java:4717)
	at java.util.regex.Pattern$Ques.match(Pattern.java:4182)
	at java.util.regex.Pattern$Curly.match0(Pattern.java:4272)
	at java.util.regex.Pattern$Curly.match(Pattern.java:4234)
	at java.util.regex.Pattern$GroupHead.match(Pattern.java:4658)
	at java.util.regex.Pattern$Loop.match(Pattern.java:4785)
	at java.util.regex.Pattern$GroupTail.match(Pattern.java:4717)
	at java.util.regex.Pattern$Ques.match(Pattern.java:4182)
	at java.util.regex.Pattern$Curly.match0(Pattern.java:4272)
	at java.util.regex.Pattern$Curly.match(Pattern.java:4234)
	at java.util.regex.Pattern$GroupHead.match(Pattern.java:4658)
	at java.util.regex.Pattern$Loop.matchInit(Pattern.java:4804)
	at java.util.regex.Pattern$Prolog.match(Pattern.java:4741)
	at java.util.regex.Pattern$Begin.match(Pattern.java:3525)
	at java.util.regex.Matcher.match(Matcher.java:1270)
	at java.util.regex.Matcher.matches(Matcher.java:604)
	at com.xxx.xxx.util4sysmng.ValidateUtil.checkEmail(ValidateUtil.java:30)
	at com.xxx.xxx.register.action.RegisterController.regAccountSendVcode(RegisterController.java:538)
	at com.xxx.xxx.register.action.RegisterController$$FastClassByCGLIB$$58ed8719.invoke(<generated>)
	at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:191)
	at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocation.invokeJoinpoint(Cglib2AopProxy.java:689)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
	at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80)
	at com.xxx.prometheus.aspect.PrometheusAspect.process(PrometheusAspect.java:35)
	at sun.reflect.GeneratedMethodAccessor121.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:497)
	at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
	at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)
	at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
	at org.springframework.aop.framework.adapter.ThrowsAdviceInterceptor.invoke(ThrowsAdviceInterceptor.java:124)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:622)
	at com.xxx.xxx.register.action.RegisterController$$EnhancerByCGLIB$$972a02bd.regAccountSendVcode(<generated>)
	at sun.reflect.GeneratedMethodAccessor124.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:497)
	at org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:212)
	at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:126)
	at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:96)
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:617)
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:578)
	at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:80)
	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:900)
	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:827)
	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882)
	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:778)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:723)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at com.xxx.xxx.sysmng.filter.SysmngSecurityFilter.doFilter(SysmngSecurityFilter.java:46)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:76)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
	at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:615)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
	at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:861)
	at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:606)
	at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
	at java.lang.Thread.run(Thread.java:745)

通过上面这段内容分析，在正则验证时出现大量线程等待，一直消耗系统CPU，最终造成服务处于假死状态，无法响应。

定位到具体的代码，经过测试 确认是验证Email的一个正则表达式有问题。代码中使用的Email正则表达式是这样写的：

1
^([a-z0-9A-Z]+[-|\\._]?)+[a-z0-9A-Z]@([a-z0-9A-Z]+(-[a-z0-9A-Z]+)?\\.)+[a-zA-Z]{2,}$

测试代码

1
2
3
4
5
6
7
8
9
@Test
public void testRegexFailed() {
  String email = "dnjnfslkffkjkjkslioeo9edkdjfks";
  String regex = "^([a-z0-9A-Z]+[-|_|\\\\.]?)*[a-z0-9A-Z]@([a-z0-9A-Z]+(-[a-z0-9A-Z]+)?\\\\.)+[a-z0-9A-Z]{2,}$";

  Pattern pattern = Pattern.compile(regex);
  Matcher matcher = pattern.matcher(email);
  System.out.println(email + " : " + matcher.matches());
}

这段代码会出现死循环，使我电脑消耗CPU急剧增加，我在测试过程中打印了该进程消耗系统资源的数据

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
chenbin@chenbin-ThinkPad:~$ jps 
23617 Launcher 
21422 JUnitStarter 
chenbin@chenbin-ThinkPad:~$ top -Hp 21422
Threads: 16 total, 1 running, 15 sleeping, 0 stopped, 0 zombie 
%Cpu(s): 30.8 us, 3.6 sy, 0.0 ni, 65.4 id, 0.1 wa, 0.0 hi, 0.1 si, 0.0 st 
KiB Mem : 7861372 total, 202784 free, 6652340 used, 1006248 buff/cache 
KiB Swap: 8076284 total, 3543620 free, 4532664 used. 872480 avail Mem 

PID   USER    PR NI VIRT     RES   SHR S% CPU% MEM TIME+ COMMAND 
21425 chenbin 20 0 4468684 100360 18136 R 99.7 1.3 0:22.25 java 
21422 chenbin 20 0 4468684 100360 18136 S 0.0 1.3 0:00.00 java 
21434 chenbin 20 0 4468684 100360 18136 S 0.0 1.3 0:00.00 java 
21435 chenbin 20 0 4468684 100360 18136 S 0.0 1.3 0:00.00 java 
21436 chenbin 20 0 4468684 100360 18136 S 0.0 1.3 0:00.00 java 
21437 chenbin 20 0 4468684 100360 18136 S 0.0 1.3 0:00.00 java 
21438 chenbin 20 0 4468684 100360 18136 S 0.0 1.3 0:00.00 java 
21439 chenbin 20 0 4468684 100360 18136 S 0.0 1.3 0:00.00 java 
21440 chenbin 20 0 4468684 100360 18136 S 0.0 1.3 0:00.00 java 
21441 chenbin 20 0 4468684 100360 18136 S 0.0 1.3 0:00.00 java 
21442 chenbin 20 0 4468684 100360 18136 S 0.0 1.3 0:00.00 java 
21443 chenbin 20 0 4468684 100360 18136 S 0.0 1.3 0:00.88 java 
21444 chenbin 20 0 4468684 100360 18136 S 0.0 1.3 0:00.72 java 
21445 chenbin 20 0 4468684 100360 18136 S 0.0 1.3 0:00.09 java 
21446 chenbin 20 0 4468684 100360 18136 S 0.0 1.3 0:00.00 java 
21447 chenbin 20 0 4468684 100360 18136 S 0.0 1.3 0:00.00 java

测试中发现

在输入的字符串比较短的时候，验证没有问题。
但是在输入字符较长，并且不符合email规则的时候，会出现死循环。
如果输入过长，但是符合这个email规则，也不会有这个问题！

结案

最后我们只能修改代码，替换这个正则表达式。因为这是通过的表达式，而且比较复杂，我们就没有造轮子。直接在网上找的, 经过验证，发现这个网站提供的正则比较靠谱
Java Email Address Validation

END

能匹配空字符串的子匹配不要循环无限次。如果括号内的子表达式中的每一部分都可以匹配 0 次，而这个括号整体又可以匹配无限次，匹配过程中可能死循环。虽然现在有些正则表达式引擎已经通过办法避免了这种情况出现死循环了，比如 .NET 的正则表达式，但是我们仍然应该尽量避免出现这种情况。如果我们在写表达式时遇到了死循环，也可以从这一点入手。

正则表达式虽然使用起来很方便, 但是一定要慎用.

转载声明： 商业转载请联系作者获得授权,非商业转载请注明出处 © Binchencoder
访问量:   |   访客数:
Copyright © 2017 | Powered by Hexo | Theme by Snippet