>  기사  >  Java  >  Java 문제 위치 및 해결 방법 요약

Java 문제 위치 및 해결 방법 요약

高洛峰
高洛峰원래의
2017-03-20 17:17:332031검색

배경
“오프라인에서는 문제가 없습니다”, “시스템상 코드에 문제가 있을 수 없습니다”, “온라인에서 원격으로 디버깅할 수 있나요?”
온라인 문제는 개발 및 런타임 중에 발생하는 버그와 다릅니다. . 환경, 압력, 동시성 상황, 특정 비즈니스 관련. 온라인 문제의 경우 온라인 환경에서 사용할 수 있는 도구를 사용하여 문제를 찾는 데 필요한 정보를 수집하는 것이 중요합니다.
문제를 일으키는 버그 및 리소스 병목 현상에 대한 데이터를 직관적으로 얻는 것은 어렵습니다. 리소스 사용 데이터, 로그 및 기타 정보를 기반으로 문제의 근본 원인을 추론하는 것이 필요합니다. 그리고 어려운 문제의 위치를 ​​파악하려면 일반적으로 소스를 추적하기 위해 다양한 방법을 사용해야 합니다.
이 위키에는 제가 사용해본 도구들을 모아서 몇 가지 사례를 공유해봤습니다.

1. 자주 묻는 질문
1.1 가용성
서비스 가용성으로 이어지는 몇 가지 일반적인 상황은 다음과 같습니다.
a) 502 Bad Gateway
응용 시스템에서 가장 일반적인 문제는, 특히 http 기반 애플리케이션 백엔드 서비스를 완전히 사용할 수 없음을 의미하는 "502 Bad Gateway"보다 더 심각한 것은 없습니다. 가능한 이유
리소스 부족 1: 가비지 수집으로 인해 심각한 애플리케이션 중단이 발생합니다. CMS에 애플리케이션 메모리 누수가 있거나 메모리가 부족합니다.
리소스 부족 2: 서버 스레드 수 부족 낮음 및 너무 높음 쿼리가 웹 서버의 작업 스레드를 차단하는 정도
리소스 부족 4: IO 리소스 병목 현상, 온라인 환경 IO가 공유됩니다. 특히 혼합 환경에서는(다행히 CRM에는 이러한 상황이 없지만) 에이전트가 많음) 일반적으로 사용되는 log4j 로깅 도구는 기록된 각 로그 파일에 대한 독점 리소스이기도 합니다. 스레드는 로그에 데이터를 기록하기 전에 먼저 잠금을 획득해야 합니다.
... ...
다양한 OOM
b) 소켓 예외
Peer에 의한 공통 연결 재설정, Broken Pipe, EOFException
네트워크 문제: 운영자 간 및 전산실의 경우 access
프로그램 버그: 소켓이 비정상적으로 닫혔습니다
1.2 평균 응답 시간
시스템 문제가 발생할 때 가장 직관적인 증상입니다. 이 매개변수는 상황이 악화되어 다른 서비스를 감염시켜 문제가 발생하기 전에 조기 경고를 제공할 수 있습니다. 가능한 이유:
리소스 경쟁 1: CPU
리소스 경쟁 2: IO
리소스 경쟁 3: 네트워크 IO
리소스 경쟁 4: 데이터베이스
리소스 경쟁 5: solr, medis
다운스트림 인터페이스: 이상으로 인한 응답 지연
1.3 기계 알람
애플리케이션 서비스 불가에 비해 이러한 유형의 오류는 서비스 불가로 직접 이어지지 않으며 혼란이 있는 경우 여러 서비스 배포
CPU
디스크
fd
IO(네트워크 디스크)
1.4 요약
작성하는 데 시간이 오래 걸렸고, 많은 경우가 실패했습니다. 일반적으로 온라인 문제의 원인은 시스템 리소스, 응용 프로그램에 지나지 않으며 이러한 리소스와 데이터를 모니터링하고 보는 도구를 익히면 온라인 문제를 더 쉽게 찾을 수 있습니다.
2 공통 도구
2.1 Linux 도구
a) sysstat:
iostat: 읽기 및 쓰기 압력 보기

    [sankuai@cos-mop01 logs]$ iostat
    Linux 2.6.32-20131120.mt (cos-mop01.lf.sankuai.com)     2015年10月21日     _x86_64_    (4 CPU)
    avg-cpu:  %user   %nice %system %iowait  %steal   %idle
               1.88    0.00    0.87    0.12    0.05   97.07
    Device:            tps   Blk_read/s   Blk_wrtn/s   Blk_read   Blk_wrtn
    vda               1.88        57.90        12.11 2451731906  512911328
    vdb               0.01         0.40         1.41   17023940   59522616
    vdc               1.14        28.88        36.63 1223046988 1551394969
sar: CPU 네트워크 IO IO 보기, 매개변수를 활성화하여 기록 데이터 보기

    /etc/sysconfig/sysstat
    HISTORY=7
    /etc/cron.d/sysstat
    */10 * * * * root /usr/lib/sa/sa1 1 1
       
    sar -u/-r/-B/-b/-q/-P/-n -f /var/log/sa/sa09
b) top

load, cpu, mem, swap 주의
스레드별로 리소스 정보를 볼 수 있습니다(버전은 3.2.7 이상)

top - 19:33:00 up 490 days,  4:33,  2 users,  load average: 0.13, 0.39, 0.42
Tasks: 157 total,   1 running, 156 sleeping,   0 stopped,   0 zombie
Cpu(s):  4.9%us,  2.7%sy,  0.0%ni, 92.2%id,  0.0%wa,  0.0%hi,  0.0%si,  0.3%st
Mem:   5991140k total,  5788884k used,   202256k free,     4040k buffers
Swap:  2096440k total,   447332k used,  1649108k free,   232884k cached
  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  SWAP CODE DATA COMMAND
18720 sankuai   20   0 8955m 4.3g 6744 S 22.6 74.5 174:30.73    0    4 8.6g java
27794 sankuai   20   0 5715m 489m 2116 S 11.6  8.4   3922:43 121m    4 3.9g java
13233 root      20   0  420m 205m 2528 S  0.0  3.5   1885:15  91m    4 304m puppetd
21526 sankuai   20   0 2513m  69m 4484 S  0.0  1.2  45:56.28  37m    4 2.4g java
c ) vmstat

[sankuai@cos-mop01 logs]$ vmstat
procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 0  0 447332 200456   4160 234512    0    0    11     6    0    0  2  1 97  0  0
d) tcpdump

TCPIP 메시지의 세부 정보를 볼 수 있는 도구입니다. 동시에 TCPIP 프로토콜에 익숙해져야 합니다. 와이어샤크와 결합.
일반적인 시나리오는 네트워크 지연, 네트워크 패킷 손실을 분석하고 복잡한 환경의 네트워크 문제를 분석합니다.

#!/bin/bash
tcpdump -i eth0 -s 0 -l -w - dst port 3306 | strings | perl -e '
while() { chomp; next if /^[^ ]+[ ]*$/;
    if(/^(SELECT|UPDATE|DELETE|INSERT|SET|COMMIT|ROLLBACK|CREATE|DROP|ALTER|CALL)/i)
    {
        if (defined $q) { print "$q\n"; }
        $q=$_;
    } else {
        $_ =~ s/^[ \t]+//; $q.=" $_";
    }
}'
3.2 Java 도구

a) jstat

[sankuai@cos-mop01 logs]$ jstat -gc 18704
 S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
3584.0 3584.0  0.0    0.0   24064.0  13779.7   62976.0      0.0     4480.0 677.9  384.0   66.6       0    0.000   0      0.000    0.000
b) jmap

jmap -dump:format=b,file=heap.bin $pid
c) jstack 또는 kill -3

교착 상태 및 스레드 대기를 봅니다.
스레드 상태:
실행 중
TIMED_WAITING(객체 모니터에서)
TIMED_WAITING(휴면 중)
TIMED_WAITING(주차 중)
WAINTING(객체 모니터에서)
d) jhat jconsole
jhat이 jconsole을 사용하여 성능에 영향을 미치는 jmx를 통해 정보를 얻는 것은 어렵습니다.
e) gc log
-XX:+UseParallelOld
-XX:+ConcurrentMultiSweep
3.3 타사 도구
a) mat
객체 세부정보

Java 문제 위치 및 해결 방법 요약

인바운드/아웃바운드

Java 문제 위치 및 해결 방법 요약

스레드 개요

Java 문제 위치 및 해결 방법 요약

配置项

Java 문제 위치 및 해결 방법 요약

./MemoryAnalyzer -keep_unreachable_objects  heap_file
4. 案例分析
4.1 cpu高

现象:CPU报警
定位问题:
    查看CPU占用高的线程

sankuai@sin2:~$ ps H -eo user,pid,ppid,tid,time,%cpu|sort -rnk6 |head -10
sankuai  13808 13807 13808 00:00:00  8.4
sankuai  29153     1 29211 00:21:13  0.9
sankuai  29153     1 29213 00:20:01  0.8
sankuai  29153     1 29205 00:17:35  0.7
sankuai  29153     1 29210 00:11:50  0.5
sankuai  29153     1  1323 00:08:37  0.5
sankuai  29153     1 29207 00:10:02  0.4
sankuai  29153     1 29206 00:07:10  0.3
sankuai  29153     1 29208 00:06:44  0.2

 thread dump

    jstack $pid > a.txt
    printf %x $tid
        $xTID

 查找线程执行的代码

"main-SendThread(cos-zk13.lf.sankuai.com:9331)" #25 daemon prio=5 os_prio=0 tid=0x00007f78fc350000 nid=$TIDx runnable [0x00007f79c4d09000]
java.lang.Thread.State: RUNNABLE
    at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1035)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

4.2 io高

现象:磁盘IO报警
环境:需要安装sysstat工具
定位问题:
a) 查看CPU占用高的线程

1

   

pidstat -d -t -p $pid

   


b) 其他同4.1

4.3 资源
a) 数据库

"DB-Processor-13" daemon prio=5 tid=0x003edf98 nid=0xca waiting for monitor entry [0x000000000825f000]
java.lang.Thread.State: BLOCKED (on object monitor)
                at ConnectionPool.getConnection(ConnectionPool.java:102)
                - waiting to lock <0xe0375410> (a beans.ConnectionPool)
                at Service.getCount(ServiceCnt.java:111)
                at Service.insert(ServiceCnt.java:43)
"DB-Processor-14" daemon prio=5 tid=0x003edf98 nid=0xca waiting for monitor entry [0x000000000825f020]
java.lang.Thread.State: BLOCKED (on object monitor)
                at ConnectionPool.getConnection(ConnectionPool.java:102)
                - waiting to lock <0xe0375410> (a beans.ConnectionPool)
                at Service.getCount(ServiceCnt.java:111)
                at Service.insertCount(ServiceCnt.java:43)

b) log

"RMI TCP Connection(267865)-172.16.5.25" daemon prio=10
tid=0x00007fd508371000 nid=0x55ae  waiting for monitor entry
[0x00007fd4f8684000]   java.lang.Thread.State:  BLOCKED (on object monitor)
at org.apache.log4j.Category.callAppenders(Category.java:201)
-  waiting to lock <0x00000000acf4d0c0> (a org.apache.log4j.Logger)
at org.apache.log4j.Category.forcedLog(Category.java:388)
at org.apache.log4j.Category.log(Category.java:853)
at org.apache.commons.logging.impl.Log4JLogger.warn(Log4JLogger.java:234)
at com.xxx.core.common.lang.cache.remote.MemcachedClient.get(MemcachedClient.java:110)

c) web server

有两个非常重要的系统参数:

maxThread: 工作线程数

backlog:TCP连接缓存数,Jetty(ServerConnector.acceptQueueSize) Tomcat(Connector.acceptCount),高并发下设置过小会有502

 
4.4 gc

a) CMS fail
    promotion failed

    172966 2015-09-18T03:47:33.108+0800: 627188.183: [GC 627188.183: [ParNew (promotion failed)
     172967 Desired survivor size 17432576 bytes, new threshold 1 (max 6)
     172968 - age   1:   34865032 bytes,   34865032 total
     172969 : 306688K->306688K(306688K), 161.1284530 secs]627349.311: [CMS CMS: abort preclean due to time 2015-09-18T03:50:14.743+0800: 627349.818:
    [CMS-concurrent-abortable-preclean: 1.597/162.729 secs] [Times: user=174.58 sys=84.57, real=162.71 secs]
     172970  (concurrent mode failure): 1550703K->592286K(1756416K), 2.9879760 secs]
    1755158K->592286K(2063104K), [CMS Perm : 67701K->67695K(112900K)], 164.1167250 secs] [Times: user=175.61 sys=84.57, real=164.09 secs]

 concurrent fail

    [CMS2015-09-18T07:07:27.132+0800: 639182.207: [CMS-concurrent-sweep: 1.704/13.116 secs] [Times: user=17.16 sys=5.20,real=13.12 secs]
    443222 (concurrent mode failure): 1546078K->682301K(1756416K), 4.0745320 secs] 1630977K->682301K(2063104K), [CMS Perm :67700K->67693K(112900K)], 15.4860730 secs] [Times: user=19.40 sys=5.20, real=15.48 secs]

b) 连续Full GC

应用存在内存泄漏,垃圾收集会占用系统大量cpu时间,极端情况下可能发生90%以上时间在做GC的情况。
在系统使用http访问check alive或者使用了Zookeeper这种通过心跳保证存活性的应用中,会可用性异常或者被zk的master剔除。


5. 注意
    保留现场:threaddump top heapdump
    注意日志记录:文件 数据库

위 내용은 Java 문제 위치 및 해결 방법 요약의 상세 내용입니다. 자세한 내용은 PHP 중국어 웹사이트의 기타 관련 기사를 참조하세요!

성명:
본 글의 내용은 네티즌들의 자발적인 기여로 작성되었으며, 저작권은 원저작자에게 있습니다. 본 사이트는 이에 상응하는 법적 책임을 지지 않습니다. 표절이나 침해가 의심되는 콘텐츠를 발견한 경우 admin@php.cn으로 문의하세요.