准備
本次測試具備的環境很簡單,項目都是 java 項目,jdk 為1.7(1.8 也成),tomcat 為7版本,war 包放進 tomcat 路徑下的 webapps 就成。
然后改數據庫配置文件
sql 文件放到數據庫內執行,生成相應的數據庫以及表
首頁:http://www.ganziwen.cn:8082/dangdang/main/main.jsp
注冊頁面:http://www.ganziwen.cn:8082/dangdang/user/registForm.jsp
線程棧死鎖
問題描述
數據庫保證已經完全連上,但是首頁的圖片無法加載出來
排查方案
出現這種問題嘗試結合之前講的架構從幾個方面去分析,主要是排查法:
一、請求沒法送到服務器
- 負載機 cpu、內存、網絡、磁盤
二、請求發送到服務器但是無法被處理
- 應用服務器/數據庫服務器 cpu、內存、網絡、磁盤
- 容器連接池
- 數據庫連接池
- 代碼邏輯
- sql 語句慢
- JVM 的堆內存(jmap -histo:live pid ,jmap -dump:live,format=b,file=heap.bin pid)
- gc 頻繁(jstat -gcutil pid 1000)
- 線程棧問題(jstack pid)
- 磁盤 io(nmon/sar -d/iostat -x)
排查過程
這里我們的負載機排查很好排查:直接訪問一個服務器上的其他鏈接:
從這張圖片,可以側面論證,我們的負載機是沒有問題的,最起碼可以訪問服務器,同時也說明 web 容器的連接池並沒有滿,因為可以訪問我們的 82 端口,那么嘗試從其他方面去考慮,看看 jvm 和線程棧
首先我們查一下 java 進程,得到 pid 為 8071:
# ps -ef|grep java|grep -v grep root 8071 1 0 13:10 pts/0 00:00:10 /opt/jdk1.8/bin/java -Djava.util.logging.config.file=/opt/tomcat7/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djdk.tls.ephemeralDHKeySize=2048 -Dignore.endorsed.dirs= -classpath /opt/tomcat7/bin/bootstrap.jar:/opt/tomcat7/bin/tomcat-juli.jar -Dcatalina.base=/opt/tomcat7 -Dcatalina.home=/opt/tomcat7 -Djava.io.tmpdir=/opt/tomcat7/temp org.apache.catalina.startup.Bootstrap start
然后我們看一下 jvm 的 gc 情況:
# jstat -gcutil 8071 3000 S0 S1 E O M CCS YGC YGCT FGC FGCT GCT 0.00 100.00 64.96 82.81 96.73 92.25 25 0.189 1 0.051 0.239 0.00 100.00 64.96 82.81 96.73 92.25 25 0.189 1 0.051 0.239 0.00 100.00 65.23 82.81 96.73 92.25 25 0.189 1 0.051 0.239 0.00 100.00 65.23 82.81 96.73 92.25 25 0.189 1 0.051 0.239
可以發現。,gc 的頻率並不是很高,暫時排除是 gc 頻繁導致的
接下來看看線程棧問題:
jstack 8071 > 1.log
打開 1.log:
我們可以發現,在 http-nio-8082-exec-XXX 這種的線程中狀態幾乎都為 blocked,說明所有的 nio 的線程鎖住了,沒有可供使用的線程都被死鎖了,代表請求發送到服務器,沒有線程可供處理。而且有一個 deadblock
Found one Java-level deadlock: ============================= "http-bio-8082-exec-10": waiting to lock monitor 0x00007fa8a4005c98 (object 0x00000000e161a920, a java.lang.Object), which is held by "http-bio-8082-exec-8" "http-bio-8082-exec-8": waiting to lock monitor 0x00007fa888005c98 (object 0x00000000e16159d8, a java.lang.Object), which is held by "http-bio-8082-exec-10"
我們看到這里,大概可以判斷到應該是線程棧死鎖導致的,而且可以看到在鎖住的線程調用的方法的路徑以及方法名是:org.tarena.common 路徑下的 DbUtil類 路徑下的 getConnection 方法的 43 行(DbUtil.java:43)
"http-nio-8082-exec-109" #139 daemon prio=5 os_prio=0 tid=0x00007f915c840800 nid=0x2087 waiting for monitor entry [0x00007f91336b2000] java.lang.Thread.State: BLOCKED (on object monitor) at org.tarena.common.DbUtil.getConnection(DbUtil.java:43) - waiting to lock <0x00000000ec36cbb8> (a java.lang.Object) at org.tarena.dao.impl.DangDAOImpl.getConnection(DangDAOImpl.java:18) at org.tarena.dao.impl.BookDAOImpl.findHotBoardBooks(BookDAOImpl.java:159) at org.tarena.action.main.HotBoardBook.execute(HotBoardBook.java:20) at sun.reflect.GeneratedMethodAccessor55.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.opensymphony.xwork2.DefaultActionInvocation.invokeAction(DefaultActionInvocation.java:441) at com.opensymphony.xwork2.DefaultActionInvocation.invokeActionOnly(DefaultActionInvocation.java:280) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:243) at com.opensymphony.xwork2.interceptor.DefaultWorkflowInterceptor.doIntercept(DefaultWorkflowInterceptor.java:165) at com.opensymphony.xwork2.interceptor.MethodFilterInterceptor.intercept(MethodFilterInterceptor.java:87) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:237) at com.opensymphony.xwork2.validator.ValidationInterceptor.doIntercept(ValidationInterceptor.java:252) at org.apache.struts2.interceptor.validation.AnnotationValidationInterceptor.doIntercept(AnnotationValidationInterceptor.java:68) at com.opensymphony.xwork2.interceptor.MethodFilterInterceptor.intercept(MethodFilterInterceptor.java:87) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:237) at com.opensymphony.xwork2.interceptor.ConversionErrorInterceptor.intercept(ConversionErrorInterceptor.java:122) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:237) at com.opensymphony.xwork2.interceptor.ParametersInterceptor.doIntercept(ParametersInterceptor.java:195) at com.opensymphony.xwork2.interceptor.MethodFilterInterceptor.intercept(MethodFilterInterceptor.java:87) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:237) at com.opensymphony.xwork2.interceptor.ParametersInterceptor.doIntercept(ParametersInterceptor.java:195) at com.opensymphony.xwork2.interceptor.MethodFilterInterceptor.intercept(MethodFilterInterceptor.java:87) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:237) at com.opensymphony.xwork2.interceptor.StaticParametersInterceptor.intercept(StaticParametersInterceptor.java:179) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:237) at org.apache.struts2.interceptor.MultiselectInterceptor.intercept(MultiselectInterceptor.java:75) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:237) at org.apache.struts2.interceptor.CheckboxInterceptor.intercept(CheckboxInterceptor.java:94) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:237) at org.apache.struts2.interceptor.FileUploadInterceptor.intercept(FileUploadInterceptor.java:235) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:237) at com.opensymphony.xwork2.interceptor.ModelDrivenInterceptor.intercept(ModelDrivenInterceptor.java:89) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:237) at com.opensymphony.xwork2.interceptor.ScopedModelDrivenInterceptor.intercept(ScopedModelDrivenInterceptor.java:130) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:237) at org.apache.struts2.interceptor.debugging.DebuggingInterceptor.intercept(DebuggingInterceptor.java:267) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:237) at com.opensymphony.xwork2.interceptor.ChainingInterceptor.intercept(ChainingInterceptor.java:126) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:237) at com.opensymphony.xwork2.interceptor.PrepareInterceptor.doIntercept(PrepareInterceptor.java:138) at com.opensymphony.xwork2.interceptor.MethodFilterInterceptor.intercept(MethodFilterInterceptor.java:87) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:237) at com.opensymphony.xwork2.interceptor.I18nInterceptor.intercept(I18nInterceptor.java:165) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:237) at org.apache.struts2.interceptor.ServletConfigInterceptor.intercept(ServletConfigInterceptor.java:164) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:237) at com.opensymphony.xwork2.interceptor.AliasInterceptor.intercept(AliasInterceptor.java:179) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:237) at com.opensymphony.xwork2.interceptor.ExceptionMappingInterceptor.intercept(ExceptionMappingInterceptor.java:176) at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:237) at org.apache.struts2.impl.StrutsActionProxy.execute(StrutsActionProxy.java:52) at org.apache.struts2.dispatcher.Dispatcher.serviceAction(Dispatcher.java:488) at org.apache.struts2.dispatcher.ng.ExecuteOperations.executeAction(ExecuteOperations.java:77) at org.apache.struts2.dispatcher.ng.filter.StrutsPrepareAndExecuteFilter.doFilter(StrutsPrepareAndExecuteFilter.java:91) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:494) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:104) at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:1025) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:445) at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1137) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1775) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1734) - locked <0x00000000e0f1c108> (a org.apache.tomcat.util.net.NioChannel) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:748)
我們切換到該路徑下:這里不可以直接 vi ,將文件 down 到本地利用 jd-gui 反編譯 .class文件成為一個 .java 文件
# pwd /opt/tomcat7/webapps/dangdang/WEB-INF/classes/org/tarena/common
# ll
total 36
-rw-r--r-- 1 root root 737 Jun 24 2016 BooToStrUtil.class
-rw-r--r-- 1 root root 338 Jun 24 2016 Constant.class
-rw-r--r-- 1 root root 2697 Jun 24 2016 CookieUtil.class
-rw-r--r-- 1 root root 371 Jun 24 2016 DangException.class
-rw-r--r-- 1 root root 2954 Jun 24 2016 DbUtil.class
-rw-r--r-- 1 root root 1397 Jun 24 2016 DegistUtil.class
-rw-r--r-- 1 root root 440 Jun 24 2016 EmailUtil.class
-rw-r--r-- 1 root root 2998 Jun 24 2016 ImageUtil.class
-rw-r--r-- 1 root root 2237 Jun 24 2016 VerifyUtil.clas
反編譯打開如下:
1 // 2 // Source code recreated from a .class file by IntelliJ IDEA 3 // (powered by Fernflower decompiler) 4 // 5 6 package org.tarena.common; 7 8 import java.sql.Connection; 9 import java.sql.DriverManager; 10 import java.sql.SQLException; 11 import java.util.Properties; 12 13 public class DbUtil { 14 private static Object ds = new Object(); 15 private static Object connLocal = new Object(); 16 private static String driver; 17 private static String url; 18 private static String dbUser; 19 private static String dbPwd; 20 public static int maxConnection; 21 public static int countConnection; 22 23 static { 24 Properties pro = new Properties(); 25 26 try { 27 pro.load(DbUtil.class.getClassLoader().getResourceAsStream("dbcp.properties")); 28 url = pro.getProperty("url"); 29 driver = pro.getProperty("driverClassName"); 30 dbUser = pro.getProperty("username"); 31 dbPwd = pro.getProperty("password"); 32 maxConnection = Integer.parseInt(pro.getProperty("maxActive")); 33 Class.forName(driver); 34 } catch (Exception var2) { 35 var2.printStackTrace(); 36 } 37 38 } 39 40 public DbUtil() { 41 } 42 43 public static Connection getConnection() throws SQLException { 44 synchronized(ds) { 45 Connection connection = null; 46 47 try { 48 synchronized(connLocal) { 49 connection = DriverManager.getConnection(url, dbUser, dbPwd); 50 System.out.println(countConnection + ":" + maxConnection + ":" + (countConnection > maxConnection)); 51 if (countConnection > maxConnection) { 52 throw new RuntimeException(); 53 } 54 55 ++countConnection; 56 System.out.println(countConnection); 57 } 58 } catch (SQLException var4) { 59 var4.printStackTrace(); 60 } 61 62 return connection; 63 } 64 } 65 66 public static void closeConnection(Connection conn) throws SQLException { 67 synchronized(connLocal) { 68 if (conn != null) { 69 synchronized(ds) { 70 System.out.println("->cloase"); 71 } 72 } 73 74 } 75 } 76 }
這里是因為加了一個同步鎖:synchronized(ds) ,要解決把這里刪掉就成了。
如果是其他問題:
應用服務器 cpu :top,看 CPU 使用率和平均負載
服務器 io 問題:iostat -x或者 sar -d
- avgrq-sz:每個IO的平均扇區數,即所有請求的平均大小,以扇區(512字節)為單位
- avgqu-sz:平均為完成的IO請求數量,即平均意義山的請求隊列長度
# iostat -x Linux 2.6.32-754.9.1.el6.x86_64 (xiaowenshu) 02/03/2019 _x86_64_ (1 CPU)avg-cpu: %user %nice %system %iowait %steal %idle
0.49 0.00 0.28 0.02 0.00 99.21Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s avgrq-sz avgqu-sz await r_await w_await svctm %util
vda 0.01 0.70 0.06 0.38 3.68 8.65 28.25 0.00 5.68 1.67 6.30 1.11 0.05
# sar -d
Linux 2.6.32-754.9.1.el6.x86_64 (xiaowenshu) 02/03/2019 x86_64 (1 CPU)
03:20:36 PM DEV tps rd_sec/s wr_sec/s avgrq-sz avgqu-sz await svctm %util
03:20:38 PM dev252-0 1.51 0.00 44.22 29.33 0.00 3.00 3.00 0.45
03:20:40 PM dev252-0 2.01 0.00 40.20 20.00 0.00 1.00 0.75 0.15
03:20:42 PM dev252-0 1.99 0.00 31.84 16.00 0.00 0.50 0.50 0.10
Average: dev252-0 1.84 0.00 38.73 21.09 0.00 1.36 1.27 0.23
數據庫連接池:我們的連接池有 151 個,遠遠沒有達到
堆內存溢出
重現問題:壓測該頁面(里面有倆請求)
壓測后報錯:OOM(heap space)
java.lang.OutOfMemoryError: Java heap space at java.util.Arrays.copyOf(Arrays.java:3332) at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:124) at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:448) at java.lang.StringBuilder.append(StringBuilder.java:136) at org.apache.catalina.valves.ErrorReportValve.getPartialServletStackTrace(ErrorReportValve.java:332) at org.apache.catalina.valves.ErrorReportValve.report(ErrorReportValve.java:251) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:148) at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:1025) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:445) at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1137) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1775) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1734) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:748)
而且壓測過程中,看我們的 cpu :
# top top - 17:14:41 up 8 days, 5:15, 7 users, load average: 0.22, 0.05, 0.02 Tasks: 113 total, 2 running, 111 sleeping, 0 stopped, 0 zombie Cpu(s): 99.3%us, 0.4%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.4%si, 0.0%st Mem: 2054084k total, 1978048k used, 76036k free, 135632k buffers Swap: 0k total, 0k used, 0k free, 724640k cachedPID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
8591 root 20 0 2551m 640m 14m S 99.0 31.9 3:50.78 java
並且 full gc 次數誇張:
# jstat -gcutil 8591 1000
S0 S1 E O M CCS YGC YGCT FGC FGCT GCT
100.00 0.00 100.00 100.00 96.53 91.74 71 0.944 2485 269.686 270.630
100.00 0.00 100.00 100.00 96.53 91.74 71 0.944 2495 271.024 271.967
100.00 0.00 100.00 100.00 96.53 91.74 71 0.944 2503 272.043 272.986
100.00 0.00 100.00 100.00 96.53 91.74 71 0.944 2513 273.024 273.967
100.00 0.00 100.00 100.00 96.53 91.74 71 0.944 2523 274.110 275.053
100.00 0.00 100.00 100.00 96.53 91.74 71 0.944 2533 275.096 276.040
100.00 0.00 100.00 100.00 96.53 91.74 71 0.944 2541 276.077 277.020
那么,我們有兩種方式去分析堆內存溢出
- jmap -histo:live pid
- jmap -dump:live,format=b,file=heap.bin pid
先看相對簡單的第一種:
num #instances #bytes class name ---------------------------------------------- 1: 56192 473581544 [I 2: 76980 12271064 [C 3: 1657 3424216 [B 4: 74385 1785240 java.lang.String 5: 12044 1127904 [Ljava.util.concurrent.ConcurrentHashMap$Node; 6: 11899 1047112 org.apache.catalina.session.StandardSession 7: 31696 1014272 java.util.concurrent.ConcurrentHashMap$Node 8: 29348 939136 java.util.HashMap$Node 9: 5899 849456 java.awt.image.DirectColorModel 10: 12146 837528 [Ljava.util.Hashtable$Entry; 11: 7973 819408 [Ljava.util.HashMap$Node; 12: 12191 780224 java.util.concurrent.ConcurrentHashMap 13: 5898 613392 sun.awt.image.IntegerInterleavedRaster 14: 5153 586696 java.lang.Class 15: 12083 579984 java.util.Hashtable 16: 8503 527832 [Ljava.lang.Object; 17: 5409 475992 java.lang.reflect.Method 18: 5898 424656 sun.awt.image.BufImgSurfaceData 19: 8740 419520 java.util.HashMap 20: 16394 393456 java.util.ArrayList
這里,我們沒有發現開發寫的方法,類似 org 的這種,有也是 tomcat 自帶的一些。最多的是 int 類型和 char等
所以我們用方法2,dump 下來后用 mat 分析,文件較大,dump 時間較長,如圖,可以發現是 ImageUtil 這個類導致的,創建的對象全部寫入了一個 ArrayList List ,調用之后沒有置為 NULL,所以把堆內存占滿了,要修復的話,把 ArrayList 置為 NULL 就行
棧溢出
點擊我的當當:
結果:狀態碼為 500 ,提示如下,為棧溢出,同時顯示了類的路徑以及名字
java.lang.StackOverflowError
org.tarena.action.order.OrderInfoAction.recursion(OrderInfoAction.java:29)
org.tarena.action.order.OrderInfoAction.recursion(OrderInfoAction.java:29)
org.tarena.action.order.OrderInfoAction.recursion(OrderInfoAction.java:29)
org.tarena.action.order.OrderInfoAction.recursion(OrderInfoAction.java:29)
org.tarena.action.order.OrderInfoAction.recursion(OrderInfoAction.java:29)
org.tarena.action.order.OrderInfoAction.recursion(OrderInfoAction.java:29)
數據庫連接池不釋放
過程:壓測一個商品的詳情頁請求,看看報錯如何
結果:
沒有響應
分析過程:
按照我們剛剛的過程
一、請求沒法送到服務器
- 負載機 cpu、內存、網絡、磁盤
二、請求發送到服務器但是無法被處理
- 應用服務器/數據庫服務器 cpu、內存、網絡、磁盤
- 容器連接池
- 數據庫連接池
- 代碼邏輯
- sql 語句慢
- JVM 的堆內存(jmap -histo:live pid ,jmap -dump:live,format=b,file=heap.bin pid)
- gc 頻繁(jstat -gcutil pid 1000)
- 線程棧問題(jstack pid)
- 磁盤 io(nmon/sar -d/iostat -x)
先看 8080 能不能訪問:可以訪問
這說明 tomcat 連接池沒問題,網路內存也沒問題
接下來看 cpu ,top:沒問題
]# top top - 18:54:44 up 8 days, 6:55, 3 users, load average: 0.00, 0.00, 0.00 Tasks: 101 total, 1 running, 100 sleeping, 0 stopped, 0 zombie Cpu(s): 0.3%us, 0.3%sy, 0.0%ni, 99.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Mem: 2054084k total, 1817816k used, 236268k free, 186872k buffers Swap: 0k total, 0k used, 0k free, 833836k cachedPID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1178 root 10 -10 123m 9.9m 5456 S 0.3 0.5 47:35.04 AliYunDun
1884 root 20 0 221m 9.9m 5064 S 0.3 0.5 2:29.35 docker
9136 root 20 0 2587m 316m 16m S 0.3 15.8 0:41.86 java
線程棧以及 jvm 都沒問題,問題在哪?
我們看下數據庫連接池,發現連接池很多被 e6mall 占用,但是 sleep 了,我們可以看到有 30 個連接池被占用了(ip和db都要符合規則)。
之前我們有提到過,數據庫連接池除了在數據庫內部設置最大連接數,在程序內也有,我們的數據庫最大連接數查詢命令為:show variables like '%max_connections%';並且可以查到,是 151 個。接下來我們去程序中查看數據庫的屬性連接
我們的最大連接數一般是在配置文件內,去 e6mall 內查看 jdbc.properties:(xxx為我的 ip)
jdbc.driverClassName=com.mysql.jdbc.Driver jdbc.url=jdbc\:mysql\://xx.xxx.xxx.xxx\:3306/e6mall?useUnicode\=true&characterEncoding\=utf-8&autoReconnect\=true&zeroDateTimeBehavior\=round jdbc.username=root jdbc.password=123456
可以看到只有基礎的屬性配置,但是沒有詳細的連接配置,我們的 dangdang 是有的,那么這里在哪配的呢?
e6mall/WEB-INF/classes/applicationContext.xml
<?xml version="1.0" encoding="UTF-8"?> <beans xmlns="http://www.springframework.org/schema/beans" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:p="http://www.springframework.org/schema/p" xmlns:context="http://www.springframework.org/schema/context" xmlns:aop="http://www.springframework.org/schema/aop" xmlns:tx="http://www.springframework.org/schema/tx" xsi:schemaLocation=" http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-3.0.xsd http://www.springframework.org/schema/context http://www.springframework.org/schema/context/spring-context-3.0.xsd http://www.springframework.org/schema/aop http://www.springframework.org/schema/aop/spring-aop-3.0.xsd http://www.springframework.org/schema/tx http://www.springframework.org/schema/tx/spring-tx-3.0.xsd"><span style="color: #0000ff;"><</span><span style="color: #800000;">bean </span><span style="color: #ff0000;">id</span><span style="color: #0000ff;">="propertyConfigurer"</span><span style="color: #ff0000;"> class</span><span style="color: #0000ff;">="org.springframework.beans.factory.config.PropertyPlaceholderConfigurer"</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">property </span><span style="color: #ff0000;">name</span><span style="color: #0000ff;">="locations"</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">list</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span>classpath:jdbc.properties<span style="color: #0000ff;"></</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"></</span><span style="color: #800000;">list</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"></</span><span style="color: #800000;">property</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"></</span><span style="color: #800000;">bean</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">bean </span><span style="color: #ff0000;">id</span><span style="color: #0000ff;">="velocityEngine"</span><span style="color: #ff0000;"> class</span><span style="color: #0000ff;">="org.springframework.ui.velocity.VelocityEngineFactoryBean"</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">property </span><span style="color: #ff0000;">name</span><span style="color: #0000ff;">="velocityProperties"</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">props</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">prop </span><span style="color: #ff0000;">key</span><span style="color: #0000ff;">="resource.loader"</span><span style="color: #0000ff;">></span>class<span style="color: #0000ff;"></</span><span style="color: #800000;">prop</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">prop </span><span style="color: #ff0000;">key</span><span style="color: #0000ff;">="class.resource.loader.class"</span><span style="color: #0000ff;">></span><span style="color: #000000;"> org.apache.velocity.runtime.resource.loader.ClasspathResourceLoader </span><span style="color: #0000ff;"></</span><span style="color: #800000;">prop</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">prop </span><span style="color: #ff0000;">key</span><span style="color: #0000ff;">="velocimacro.library"</span><span style="color: #0000ff;">></</span><span style="color: #800000;">prop</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"></</span><span style="color: #800000;">props</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"></</span><span style="color: #800000;">property</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"></</span><span style="color: #800000;">bean</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">bean </span><span style="color: #ff0000;">id</span><span style="color: #0000ff;">="dataSource"</span><span style="color: #ff0000;"> class</span><span style="color: #0000ff;">="com.mchange.v2.c3p0.ComboPooledDataSource"</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">property </span><span style="color: #ff0000;">name</span><span style="color: #0000ff;">="driverClass"</span><span style="color: #ff0000;"> value</span><span style="color: #0000ff;">="${jdbc.driverClassName}"</span> <span style="color: #0000ff;">/></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">property </span><span style="color: #ff0000;">name</span><span style="color: #0000ff;">="jdbcUrl"</span><span style="color: #ff0000;"> value</span><span style="color: #0000ff;">="${jdbc.url}"</span> <span style="color: #0000ff;">/></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">property </span><span style="color: #ff0000;">name</span><span style="color: #0000ff;">="user"</span><span style="color: #ff0000;"> value</span><span style="color: #0000ff;">="${jdbc.username}"</span> <span style="color: #0000ff;">/></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">property </span><span style="color: #ff0000;">name</span><span style="color: #0000ff;">="password"</span><span style="color: #ff0000;"> value</span><span style="color: #0000ff;">="${jdbc.password}"</span> <span style="color: #0000ff;">/></span> <span style="color: #008000;"><!--</span><span style="color: #008000;">連接池中保留的最小連接數。 </span><span style="color: #008000;">--></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">property </span><span style="color: #ff0000;">name</span><span style="color: #0000ff;">="minPoolSize"</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span>5<span style="color: #0000ff;"></</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"></</span><span style="color: #800000;">property</span><span style="color: #0000ff;">></span> <span style="color: #008000;"><!--</span><span style="color: #008000;">連接池中保留的最大連接數。Default: 15 </span><span style="color: #008000;">--></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">property </span><span style="color: #ff0000;">name</span><span style="color: #0000ff;">="maxPoolSize"</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span><span style="background-color: #ff0000;">30</span><span style="color: #0000ff;"></</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"></</span><span style="color: #800000;">property</span><span style="color: #0000ff;">></span> <span style="color: #008000;"><!--</span><span style="color: #008000;">初始化時獲取的連接數,取值應在minPoolSize與maxPoolSize之間。Default: 3 </span><span style="color: #008000;">--></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">property </span><span style="color: #ff0000;">name</span><span style="color: #0000ff;">="initialPoolSize"</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span>10<span style="color: #0000ff;"></</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"></</span><span style="color: #800000;">property</span><span style="color: #0000ff;">></span> <span style="color: #008000;"><!--</span><span style="color: #008000;">最大空閑時間,60秒內未使用則連接被丟棄。若為0則永不丟棄。Default: 0 </span><span style="color: #008000;">--></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">property </span><span style="color: #ff0000;">name</span><span style="color: #0000ff;">="maxIdleTime"</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span>60<span style="color: #0000ff;"></</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"></</span><span style="color: #800000;">property</span><span style="color: #0000ff;">></span> <span style="color: #008000;"><!--</span><span style="color: #008000;">當連接池中的連接耗盡的時候c3p0一次同時獲取的連接數。Default: 3 </span><span style="color: #008000;">--></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">property </span><span style="color: #ff0000;">name</span><span style="color: #0000ff;">="acquireIncrement"</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span>5<span style="color: #0000ff;"></</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"></</span><span style="color: #800000;">property</span><span style="color: #0000ff;">></span> <span style="color: #008000;"><!--</span><span style="color: #008000;"> JDBC的標准參數,用以控制數據源內加載的PreparedStatements數量。但由於預緩存的statements 屬於單個connection而不是整個連接池。所以設置這個參數需要考慮到多方面的因素。 如果maxStatements與maxStatementsPerConnection均為0,則緩存被關閉。Default: 0 </span><span style="color: #008000;">--></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">property </span><span style="color: #ff0000;">name</span><span style="color: #0000ff;">="maxStatements"</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span>0<span style="color: #0000ff;"></</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"></</span><span style="color: #800000;">property</span><span style="color: #0000ff;">></span> <span style="color: #008000;"><!--</span><span style="color: #008000;">每60秒檢查所有連接池中的空閑連接。Default: 0 </span><span style="color: #008000;">--></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">property </span><span style="color: #ff0000;">name</span><span style="color: #0000ff;">="idleConnectionTestPeriod"</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span>60<span style="color: #0000ff;"></</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"></</span><span style="color: #800000;">property</span><span style="color: #0000ff;">></span> <span style="color: #008000;"><!--</span><span style="color: #008000;">定義在從數據庫獲取新連接失敗后重復嘗試的次數。Default: 30 </span><span style="color: #008000;">--></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">property </span><span style="color: #ff0000;">name</span><span style="color: #0000ff;">="acquireRetryAttempts"</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span>30<span style="color: #0000ff;"></</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"></</span><span style="color: #800000;">property</span><span style="color: #0000ff;">></span> <span style="color: #008000;"><!--</span><span style="color: #008000;"> 獲取連接失敗將會引起所有等待連接池來獲取連接的線程拋出異常。但是數據源仍有效 保留,並在下次調用getConnection()的時候繼續嘗試獲取連接。如果設為true,那么在嘗試 獲取連接失敗后該數據源將申明已斷開並永久關閉。Default: false </span><span style="color: #008000;">--></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">property </span><span style="color: #ff0000;">name</span><span style="color: #0000ff;">="breakAfterAcquireFailure"</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span>false<span style="color: #0000ff;"></</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"></</span><span style="color: #800000;">property</span><span style="color: #0000ff;">></span> <span style="color: #008000;"><!--</span><span style="color: #008000;"> 因性能消耗大請只在需要的時候使用它。如果設為true那么在每個connection提交的 時候都將校驗其有效性。建議使用idleConnectionTestPeriod或automaticTestTable 等方法來提升連接測試的性能。Default: false </span><span style="color: #008000;">--></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">property </span><span style="color: #ff0000;">name</span><span style="color: #0000ff;">="testConnectionOnCheckout"</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"><</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span>false<span style="color: #0000ff;"></</span><span style="color: #800000;">value</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"></</span><span style="color: #800000;">property</span><span style="color: #0000ff;">></span> <span style="color: #0000ff;"></</span><span style="color: #800000;">bean</span><span style="color: #0000ff;">></span></pre>
說明最大連接數我配了 30 ,就連上了 30 ,初步判斷是數據庫連接池不釋放,那么怎么驗證?我們把 30 改成 120 再壓測,如果數據庫連接池又被占滿了,則可以判斷是連接池不釋放導致的。
果然,120個又被占滿,說明是數據庫連接池不釋放導致的問題
總結
根據問題現象,去定位問題。具體方式是根據我們的架構拓撲圖去排查,有些是經驗推斷,以及日志內的分析去定位大致范圍。還有比較重要的能定位問題的:日志內的埋點的時間信息。在日志內打印接口的調用時間。如果響應時間長,在日志內打出來接口的調用時間,再減去數據庫內發生的時間,就是接受請求之前所花費的時間。