Movatterモバイル変換


[0]ホーム

URL:


Norito Agetsuma, profile picture
Uploaded byNorito Agetsuma
PDF, PPTX44,758 views

Javaトラブルに備えよう #jjug_ccc #ccc_h2

JJUG CCC 2014 Spring #ccc_h2 のスライドです

Embed presentation

Download as PDF, PPTX
【JJUG  CCC  2014  Spring  H-­‐2】Javaトラブルに備えよう日本Javaユーザグループ 上妻 宜人 (あげつま のりと)はてなブログ : n-agetsuma.hatenablog.com
自己紹介上妻 宜人 (あげつま のりと)n  電話の裏側を作っている会社で働いていますn  Java/APサーバの社内技術サポート、トラブル解析n  Blog 『見習いプログラミング日記』【JJUG  CCC  2014  Spring  H-­‐2】
Javaトラブルというと  どんなことを思い浮かべますか?【JJUG  CCC  2014  Spring  H-­‐2】
Java  Heap  Size  6me  -­‐Xmx:  4G3GB  2GB  1GB  java.lang.OutOfMemoryError:    Java  heap  space【JJUG  CCC  2014  Spring  H-­‐2】
STOP SLOW突然の無応答  or  唐突すぎるスローダウン【JJUG  CCC  2014  Spring  H-­‐2】
Javaトラブルランキング  (私の感覚調べ)第1位OutOfMemoryError  の発生  (Heap、Perm、”unable  to  create  new  na6ve  Thread”)第2位スローダウン  /  タイムアウト  (SQL遅延、無限ループ、JTAタイムアウト  など)  第3位OSの設定漏れ  (“Too  many  open  files”  など)  【JJUG  CCC  2014  Spring  H-­‐2】
日常のJavaトラブル対応で  最も苦労していること【JJUG  CCC  2014  Spring  H-­‐2】
情報がない、再現もしない  【JJUG  CCC  2014  Spring  H-­‐2】
GCログがない  クラスヒストグラムがない  ヒープダンプがない  スレッドダンプがない  プロファイラがアタッチできない  APログが出てない  JMXモニタリング情報がない  【JJUG  CCC  2014  Spring  H-­‐2】
トラブル発生に備えて、  まずは事実の収集が大切です【JJUG  CCC  2014  Spring  H-­‐2】
本日のテーマ【JJUG  CCC  2014  Spring  H-­‐2】
Javaトラブルに応じた  情報収集方法【JJUG  CCC  2014  Spring  H-­‐2】
本日のコンテンツOutOfMemoryErrorに備える  •  GCログによる過度なヒープ消費の発見  •  クラスヒストグラム  /  ヒープダンプによる解析スローダウン  /  タイムアウトに備える  •  スレッドダンプ と hprofプロファイラ  •  JTAタイムアウトの罠  OSの設定漏れに備える  •  too  many  open  files  •  unable  to  create  new  na6ve  thread  【JJUG  CCC  2014  Spring  H-­‐2】トラブル 第1位トラブル 第2位トラブル 第3位
本日のコンテンツOutOfMemoryErrorに備える  •  GCログによる過度なヒープ消費の発見  •  クラスヒストグラム  /  ヒープダンプによる解析スローダウン  /  タイムアウトに備える  •  スレッドダンプ と hprofプロファイラ  •  JTAタイムアウトの罠  OSの設定漏れに備える  •  too  many  open  files  •  unable  to  create  new  na6ve  thread  【JJUG  CCC  2014  Spring  H-­‐2】トラブル 第1位トラブル 第2位トラブル 第3位
【JJUG  CCC  2014  Spring  H-­‐2】Meta  SpaceOther    JVM  MemEden SurvivorOld(Tenured)Young(New)OutOfMemoryとは  :  Javaヒープ振り返りS0 S1User agetsuma =  new  User(“Norito Agetsuma”);java.lang.OutOfMemoryError:  Java  heap  spaceヒープが足りない
【JJUG  CCC  2014  Spring  H-­‐2】OutOfMemoryErrorに備える【1.予兆の確認】Java  Heap  6me  -­‐Xmx:  4G3GB  2GB  1GB  『GCログの出力』【2.発生時の解析】『ヒープダンプ』『クラスヒストグラム』num    #instances    #bytes      class  name  -­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐        1              10000            250000    java.lang.String        2                  8000            200000    foo.Sample  OldNew S0 S1.hprofファイル(バイナリ形式)負荷大負荷中25.471:  [GC  (Alloca6on  Failure)      192453K-­‐>98057K(506816K),  0.1321301  secs]  負荷小
GCログの出力  【JJUG  CCC  2014  Spring  H-­‐2】
GCログの取得【JJUG  CCC  2014  Spring  H-­‐2】java -Xms4g –Xmx4g –XX:MaxMetaspaceSize=512m-Xloggc:${WILDFLY}/standalone/log/gc.log.`date +%Y%m%d%H%M%S`-XX:+PrintGCDetails -XX:+PrintGCDateStamps-XX:+UseGCLogFileRotation-XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M改行しないJava起動オプションにあらかじめ設定する必要がある
GCログ出力の基本設定部分【JJUG  CCC  2014  Spring  H-­‐2】java -Xms4g –Xmx4g –XX:MaxMetaspaceSize=512m-Xloggc:${WILDFLY}/standalone/log/gc.log.`date +%Y%m%d%H%M%S`-XX:+PrintGCDetails -XX:+PrintGCDateStamps-XX:+UseGCLogFileRotation-XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M改行しない•  -Xloggc 出力先パスの指定•  -XX:+PrintGCDetails 詳細レベルでGCロギングする•  -XX:+PrintGCDateStamps GCログ各行に時刻を出力(デフォルトはJVM起動からの経過時間のみ)
java -Xms4g –Xmx4g –XX:MaxMetaspaceSize=512m-Xloggc:${WILDFLY}/standalone/log/gc.log.`date +%Y%m%d%H%M%S`-XX:+PrintGCDetails -XX:+PrintGCDateStamps-XX:+UseGCLogFileRotation-XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M再起動時のGCログ上書きを防止する【JJUG  CCC  2014  Spring  H-­‐2】改行しないファイル名:  gc.log.20140510123200参考:  nekopの日記  GCログを上書きしないためのTips  hjp://d.hatena.ne.jp/nekop/20111017/1318812320      年 月 日 時 分 秒
GCログのローテーション(JDK6u34〜/7u2〜/8)【JJUG  CCC  2014  Spring  H-­‐2】JavaVM gc.log.0  (最大10MB)サイズローテーションjava -Xms4g –Xmx4g –XX:MaxMetaspaceSize=512m-Xloggc:${WILDFLY}/standalone/log/gc.log.`date +%Y%m%d%H%M%S`-XX:+PrintGCDetails -XX:+PrintGCDateStamps-XX:+UseGCLogFileRotation-XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M改行しない
JDK8でGCログも少し進化しています 【JJUG  CCC  2014  Spring  H-­‐2】Java  HotSpot(TM)  64-­‐Bit  Server  VM  (25.5-­‐b02)  for  linux-­‐amd64  JRE  (1.8.0_05-­‐b13),    built  on  Mar  18  2014  00:29:27  by  "java_re"  with  gcc  4.3.0  20080428  (Red  Hat  4.3.0-­‐8)    Memory:  4k  page,  physical  1536436k(664260k  free),  swap  3080184k(2757976k  free)    CommandLine  flags:    -­‐XX:Ini6alHeapSize=536870912  -­‐XX:MaxHeapSize=536870912    -­‐XX:+PrintGC  -­‐XX:+PrintGCDateStamps                        -­‐XX:+PrintGCDetails                                        -­‐XX:+PrintGCTimeStamps  -­‐XX:+UseCompressedClassPointers  -­‐XX:+UseCompressedOops•  バージョン/メモリ情報/コマンドライン引数のファイル先頭出力•  -­‐XX:+PrintGCCause(JDK7u40〜)  のデフォルト化25.471:  [GC  (Alloca6on  Failure)    192453K-­‐>98057K(506816K)  ...  
GCViewerでログをグラフ化する【JJUG  CCC  2014  Spring  H-­‐2】hjps://github.com/chewiebug/GCViewerGC後メモリ使用量が  一定に保たれていれば正常  
【JJUG  CCC  2014  Spring  H-­‐2】OutOfMemoryErrorに備える【1.予兆の確認】Java  Heap  6me  -­‐Xmx:  4G3GB  2GB  1GB  『GCログの出力』【2.発生時の解析】『ヒープダンプ』『クラスヒストグラム』num    #instances    #bytes      class  name  -­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐        1              10000            250000    java.lang.String        2                  8000            200000    foo.Sample  OldNew S0 S1.hprofファイル(バイナリ形式)負荷大負荷中25.471:  [GC  (Alloca6on  Failure)      192453K-­‐>98057K(506816K),  0.1321301  secs]  負荷小
ヒープダンプの取得【JJUG  CCC  2014  Spring  H-­‐2】コマンドラインで取得  •  JDK6                                    ${JAVA_HOME}/bin/jmap  -­‐dump:live,format=b,file=<filename>    •  JDK7u4以降  (jmapも継続して有効)        ${JAVA_HOME/bin/jcmd  <pid>  GC.heap_dump  <filename>OOMエラー時に自動取得  (Java起動オプション)  •  -­‐XX:+HeapDumpOnOutOfMemoryError  •  -­‐XX:HeapDumpPath=${WILDFLY}/standalone/log/  負荷が大きいため、商用ではOOMエラー時自動取得がお勧め
ヒープダンプ解析  :  Eclipse  Memory  Analyzer【JJUG  CCC  2014  Spring  H-­‐2】hjp://www.eclipse.org/mat/  からダウンロード【Leak  Suspects】  ヒープ中に多いオブジェクトの表示  
【JJUG  CCC  2014  Spring  H-­‐2】OutOfMemoryErrorに備える【1.予兆の確認】Java  Heap  6me  -­‐Xmx:  4G3GB  2GB  1GB  『GCログの出力』【2.発生時の解析】『ヒープダンプ』『クラスヒストグラム』num    #instances    #bytes      class  name  -­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐        1              10000            250000    java.lang.String        2                  8000            200000    foo.Sample  OldNew S0 S1.hprofファイル(バイナリ形式)負荷大負荷中25.471:  [GC  (Alloca6on  Failure)      192453K-­‐>98057K(506816K),  0.1321301  secs]  負荷小
クラスヒストグラム【JJUG  CCC  2014  Spring  H-­‐2】8761:      num          #instances                  #bytes    class  name  -­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐        1:              3902054            104446080    [B        2:              1003304                64211456    org.hibernate.engine.spi.En6tyEntry        3:              1069377                60752992    [Ljava.lang.Object;        4:              1061657                53156392    [C        5:              1300009                41601968    [[B        6:              1092928                34973696    java.u6l.HashMap$Node        7:              2008549                32136784    java.lang.Integer        8:              1003304                32105728    org.hibernate.engine.internal.En6tyEntryContext        9:              1061269                25470456    java.lang.String      10:            1003304                24079296    net.agetsuma.performancetest.en6ty.Member  Javaヒープを多く占めているクラスをテキスト形式で取得 
クラスヒストグラム【JJUG  CCC  2014  Spring  H-­‐2】8761:      num          #instances                  #bytes    class  name  -­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐        1:              3902054            104446080    [B        2:              1003304                64211456    org.hibernate.engine.spi.En6tyEntry        3:              1069377                60752992    [Ljava.lang.Object;        4:              1061657                53156392    [C        5:              1300009                41601968    [[B        6:              1092928                34973696    java.u6l.HashMap$Node        7:              2008549                32136784    java.lang.Integer        8:              1003304                32105728    org.hibernate.engine.internal.En6tyEntryContext        9:              1061269                25470456    java.lang.String      10:            1003304                24079296    net.agetsuma.performancetest.en6ty.Member  Javaヒープを多く占めているクラスをテキスト形式で取得 JPAエンティティの大量ロード。  JPQL直すか、ScrollableResults使うなどの対処。  
クラスヒストグラムの取得【JJUG  CCC  2014  Spring  H-­‐2】コマンドラインで取得  •  JDK6                                    ${JAVA_HOME}/bin/jmap  -­‐histo:live  <pid>  •  JDK7u4以降  (jmapも継続して有効)        ${JAVA_HOME/bin/jcmd  <pid>  GC.class_histogramCTRL  +  BREAK  (Windows)  /  kill  -­‐3  で標準出力•  -­‐XX:+PrintClassHistogram  •  Windowsサービス登録されたTomcatの解析時に便利  
よくあるOOMエラーのパターン  【JJUG  CCC  2014  Spring  H-­‐2】
よくあるOOMエラーのパターン1  【突出型】•  ある機能を動かすとOutOfMemoryErrorが発生する•  多くはDBやファイルからの大量ロードが原因【JJUG  CCC  2014  Spring  H-­‐2】青のUsedHeapが急上昇。  
このパターンの解析に欲しい情報•  エラー時にどんなコードが動いていたか (アプリログ)•  OutOfMemoryErrorが発生したタイミングのヒープダンプ【JJUG  CCC  2014  Spring  H-­‐2】
突出型OOMエラー解決への情報収集•  Java起動オプションに普段から設定しておく•  OOMエラー発生時に自動的にヒープダンプで状況保存•  古くからあるJava起動オプション (1.4.2u12, 5u7 〜)【JJUG  CCC  2014  Spring  H-­‐2】-­‐XX:+HeapDumpOnOutOfMemoryError  -­‐XX:HeapDumpPath=${WILDFLY}/standalone/log/
よくあるOOMエラーのパターン2 【じわじわ型】•  長い時間をかけてOutOfMemoryErrorに至るパターン•  再現に時間がかかる or 再現しないので厄介•  原因例: ORマッパキャッシュ/自作キャッシュ/セッション肥大化 【JJUG  CCC  2014  Spring  H-­‐2】
このパターンの解析に欲しい情報•  時系列のヒープ情報 (何がじわじわ増えているのか)•  商用のみ再現するケースも多く、OutOfMemoryErrorに至る前に負荷の大きいヒープダンプを取得するのは困難【JJUG  CCC  2014  Spring  H-­‐2】なるべく軽い負荷で  時系列ヒープ情報を比較したい  
【JJUG  CCC  2014  Spring  H-­‐2】じわじわ型OOMエラー解決への情報収集『定期的なクラスヒストグラムの収集』                JDK6以前 jmap  -­‐histo:live  <pid>                JDK7,8                jcmd  <pid>  GC.class_histogram  •  ヒープダンプと比較して、負荷も軽いため商用で使いやすい•  cronを利用して定期的に取得、テキストデータをグラフ化•  増加傾向クラスの利用部分のソースコードをチェック
OSSツール HeapStats  で情報収集する•  クラスヒストグラムを定期取得&グラフ化するのは面倒•  HeapStatsではJVMにアタッチ、低オーバヘッドで自動収集•  専用アナライザでグラフ表示も可能hjp://icedtea.classpath.org/wiki/HeapStats/jpクラス別ヒープ使用量の積み上げグラフ 参照ツリー表示
java -Xms?g -Xmx?g -XX:MaxMetaspaceSize=?m-Xloggc:${WILDFLY}/standalone/log/gc.log.`date +%Y%m%d%H%M%S`-XX:+PrintGCDetails -XX:+PrintGCDateStamps-XX:+UseGCLogFileRotation-XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M-XX:+HeapDumpOnOutOfMemoryError-XX:HeapDumpPath=${WILDFLY}/standalone/log/まとめ:  OOMエラーに備えたJVMオプションGC  ログヒープ  ダンプ【JJUG  CCC  2014  Spring  H-­‐2】
本日のコンテンツOutOfMemoryErrorに備える  •  GCログによる過度なヒープ消費の発見  •  クラスヒストグラム  /  ヒープダンプによる解析スローダウン  /  タイムアウトに備える  •  スレッドダンプ と hprofプロファイラ  •  JTAタイムアウトの罠  OSの設定漏れに備える  •  too  many  open  files  •  unable  to  create  new  na6ve  thread  【JJUG  CCC  2014  Spring  H-­‐2】トラブル 第1位トラブル 第2位トラブル 第3位
アプリケーションの応答がない。  よし、今すぐ再起動で対処だ。【JJUG  CCC  2014  Spring  H-­‐2】
その問題、高確率で迷宮入りです【JJUG  CCC  2014  Spring  H-­‐2】
【JJUG  CCC  2014  Spring  H-­‐2】アプリケーションが遅い、止まった。よし、スレッドダンプ取得してから、再起動で対処だ。
スレッドダンプとはThread  AThread  BThread  CThread  Dwait waitwaitThreadDump  1回目ThreadDump  2回目ThreadDump  3回目•  コマンド実行時のJavaスレッド状態を出力する•  その瞬間、JavaVMで何が動いていたのか調査するために使う【JJUG  CCC  2014  Spring  H-­‐2】
スレッドダンプの取得【JJUG  CCC  2014  Spring  H-­‐2】•  少なくとも1.4.2にはある    kill  -­‐3  <pid>    •  JDK5以降    ${JAVA_HOME}/bin/jstack  <pid>  •  JDK7u4以降  (kill  -­‐3  /  jstackも継続して有効)        ${JAVA_HOME/bin/jcmd  <pid>  Thread.print  •  Windowsサービス登録されたTomcat画面右下の  Tomcatアイコンをクリック  
スレッドダンプ出力例"default  task-­‐10"  prio=5  6d=0x00007fef5bb8d000  nid=0xb307    wai6ng  on  condi6on  [0x000000011090a000]        java.lang.Thread.State:  TIMED_WAITING  (parking)          at  sun.misc.Unsafe.park(Na6ve  Method)          -­‐  parking  to  wait  for    <0x00000007fea15470>            at  java.u6l.concurrent.locks.LockSupport.parkNanos  …          〜  省略 〜          at  org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnec6on…              at  slowweb.SlowServlet.processRequest(SlowServlet.java:44)          at  slowweb.SlowServlet.doGet(SlowServlet.java:78)          at  javax.servlet.hjp.HjpServlet.service(HjpServlet.java:687)  アプリケーション  のスタックWildFly内部  のスタック  【JJUG  CCC  2014  Spring  H-­‐2】
スレッドダンプ出力例"default  task-­‐10"  prio=5  6d=0x00007fef5bb8d000  nid=0xb307    wai6ng  on  condi6on  [0x000000011090a000]        java.lang.Thread.State:  TIMED_WAITING  (parking)          at  sun.misc.Unsafe.park(Na6ve  Method)          -­‐  parking  to  wait  for    <0x00000007fea15470>            at  java.u6l.concurrent.locks.LockSupport.parkNanos  …          〜  省略 〜          at  org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnec6on…              at  slowweb.SlowServlet.processRequest(SlowServlet.java:44)          at  slowweb.SlowServlet.doGet(SlowServlet.java:78)          at  javax.servlet.hjp.HjpServlet.service(HjpServlet.java:687)  アプリケーション  のスタックWildFly内部  のスタック  データソースプール枯渇時の接続取得待ちスレッドの例【JJUG  CCC  2014  Spring  H-­‐2】
可視化ツールその1  『侍』【JJUG  CCC  2014  Spring  H-­‐2】hjp://samuraism.jp/samurai/ja/index.html  からダウンロードスレッドの状態を時系列に表示するのに便利  スレッドの増加傾向や、ブロックされ具合が一目でわかる
可視化ツールその2 『ThreadLogic』【JJUG  CCC  2014  Spring  H-­‐2】hjps://java.net/projects/threadlogic  からダウンロード怪しいスレッド(確認すべきスレッド)をマーキングしてくれる  特にWebLogicServer/JRockit向けが精度が高い
よくある突然の無応答トラブル例•  無限ループ  •  java.u6l.HashMapへのマルチスレッドアクセス  •  java.u6l.concurrent.ConcurrentHashMapに変更する  •  SQLの応答待ち  •  コネクションプール枯渇を併発して、全機能停止もある  •  SQL実行計画を確認し、インデックス付与やSQL書き直し  •  java.sql.setQueryTimeout(int  seconds)  で予防措置  【JJUG  CCC  2014  Spring  H-­‐2】[PostgreSQLの注意]  9.2からsetQueryTimeoutに対応。  〜9.1では『set  statement_6meout  to  <second>』をJDBC実行
ある機能が遅いのはわかったが、  原因に当たりが付かない場合【JJUG  CCC  2014  Spring  H-­‐2】
テスト環境で対象機能を動かして  『hprof』でプロファイリング【JJUG  CCC  2014  Spring  H-­‐2】
【JJUG  CCC  2014  Spring  H-­‐2】JDK付属hprofプロファイラjava  –agentlib:hprof=CPU=samples,file=<出力先指定>TRACE  301470:          sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java)          sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)    CPU  SAMPLES  BEGIN  (total  =  145881)  Sun  May  11  12:09:05  2014  rank        self      accum          count            trace  method        1  86.56%  86.56%    126270  301470  sun.nio.ch.EPollArrayWrapper.epollWait        2    7.21%    93.77%        10521    302418  java.net.SocketInputStream.socketRead0        3    1.06%    94.83%            1552    300362  java.lang.ClassLoader.defineClass0  •  SIGQUIT(kill  -­‐3)または、JavaVM終了時にテキスト出力
【JJUG  CCC  2014  Spring  H-­‐2】hprof=CPU=samples  の特徴•  集計対象は『サンプリング時にアクティブなスレッド』のみ  •  sleep()やwait()による性能遅延は集計対象外private void sleepAndWait() … {Thread.sleep(5000);wait(5000);}private List<String> moreLoop() {return Stream.generate(() -> "slow").limit(100000).collect(toList());}【検出できるもの】  •  長いアクティブスレッド  •  ループ系性能遅延 等  【検出できないもの】  •  sleepスレッド  •  waitスレッド 等  
【JJUG  CCC  2014  Spring  H-­‐2】商用での定常的収集にはJFR(有償)Java  Flight  Recorder  (JDK7u40以降)  hjp://docs.oracle.com/javase/7/docs/technotes/guides/jfr/usingjfr.html
スローダウンと関わりの深い  タイムアウトへの対処【JJUG  CCC  2014  Spring  H-­‐2】
【JJUG  CCC  2014  Spring  H-­‐2】引っかかることの多いタイムアウトhjp://www.fancyicons.com/free-­‐icon/112/hardware-­‐icon-­‐set/free-­‐server-­‐icon-­‐png/Webサーバmod_jkDBサーバmod_jk  :  reply_6meout  (worker.proper6es)  •  APサーバからの最大応答待ち時間  (デフォルト無限)  •  タイムアウト時、ブラウザには502が返る  APサーバselect  …update…JTAトランザクションタイムアウト  •  デフォルト値  :  WildFly8  5分 /  WebLogic12c  30秒  •  タイムアウトを経過しても、止まらないことがある  
【JJUG  CCC  2014  Spring  H-­‐2】JTAタイムアウト後も止まらないケースhjp://www.fancyicons.com/free-­‐icon/112/hardware-­‐icon-­‐set/free-­‐server-­‐icon-­‐png/•  応答のないSQLクエリ受信待ちの場合  •  同期ソケットI/O中にはinterrrupt()に反応しないのが要因  •  コネクションプールも浪費する要因なので厄介"default  task-­‐2”  …        java.lang.Thread.State:  RUNNABLE          at  java.net.SocketInputStream.socketRead0(Na6ve  Method)          at  java.net.SocketInputStream.read(SocketInputStream.java:150)          …            at  org.postgresql.core.v3.QueryExecutorImpl.execute  【こんなスレッドダンプには注意】
【JJUG  CCC  2014  Spring  H-­‐2】WildFly8の場合はWARNログがでてきますWARN    ARJUNA012120:    Thread[…]  not  responding  to  interrupt  when  cancelling  TX  …      -­‐-­‐  worker  marked  as  zombie  and  TX  scheduled  for  mark-­‐as-­‐rollback  1.    割込みに反応しないので、ゾンビとしてマーキングWARN  ARJUNA012113:    Transac6onReaper::doCancella6ons  worker  Thread[Transac6on  Reaper  Worker  0,5,main]  missed  interrupt  when  cancelling  TX  0:ffff7f000001:-­‐87f41d4:536f3485:49    -­‐-­‐  exi6ng  as  zombie  (zombie  count  decremented  to  0)2.    SQLが返ってきたので、ゾンビスレッドを終了(ゾンビとしてマーク) (ロールバック確定)(ゾンビスレッドが終了して、残りのゾンビは0になった)
【JJUG  CCC  2014  Spring  H-­‐2】SQLクエリタイムアウトを併用して対処•  JDBC  SQLタイムアウト  •  java.sql.statement.setQueryTimeout(int seconds)•  スレッド割込みではなく、キャンセル要求送信で実現  •  APサーバ機能  •  WildFly8    『set-­‐tx-­‐query-­‐6meout』の設定  (デフォルト無効)  •  WebLogic12c      『文タイムアウト』の設定  (デフォルト無限)  [再びPostgreSQLの注意]  9.2からsetQueryTimeoutに対応。  〜9.1では『set  statement_6meout  to  <second>』をJDBC実行
本日のコンテンツOutOfMemoryErrorに備える  •  GCログによる過度なヒープ消費の発見  •  クラスヒストグラム  /  ヒープダンプによる解析スローダウン  /  タイムアウトに備える  •  スレッドダンプ と hprofプロファイラ  •  JTAタイムアウトの罠  OSの設定漏れに備える  •  too  many  open  files  •  unable  to  create  new  na6ve  thread  【JJUG  CCC  2014  Spring  H-­‐2】トラブル 第1位トラブル 第2位トラブル 第3位
Caused  by:  java.io.FileNotFoundExcep6on:  /dev/null  (Too  many  open  files)【JJUG  CCC  2014  Spring  H-­‐2】
ファイルディスクリプタが足りない?init.d配下の起動スクリプトに ulimit –n 65536/etc/security/limits.conf【JJUG  CCC  2014  Spring  H-­‐2】
反射的に対処せずに、  まずは情報収集して事実を確認  【JJUG  CCC  2014  Spring  H-­‐2】
lsof (list open files) : オープン中ファイル一覧#  lsof  -­‐p  <java_pid>  COMMAND      PID          USER      FD      TYPE    DEVICE  SIZE/OFF        NODE  NAME  java        14090  agetsuma    337w      REG        253,2              96    524235  /home/test/sandbox/file/0  java        14090  agetsuma    338w      REG        253,2              96    524237  /home/test/sandbox/file/1  java        14090  agetsuma    339w      REG        253,2              96    524239  /home/test/sandbox/file/2  java        14090  agetsuma    340w      REG        253,2              96    524241  /home/test/sandbox/file/3  …『足りない』のではなく、シンプルにclose()漏れの可能性もある。事実を把握した上で対処することが大切【JJUG  CCC  2014  Spring  H-­‐2】
スレッド数上限に達したときも情報収集【JJUG  CCC  2014  Spring  H-­‐2】java.lang.OutOfMemoryError  :  unable  to  create  new  thread•  いきなり /etc/security/limits.conf  の nproc  を拡大しない  •  スレッドダンプ(jcmd  <pid>  Thread.print) を取得して事実確認  •  『足りない』が原因とは限らない  •  余談ですが、このOOMエラーではヒープダンプでません
【JJUG  CCC  2014  Spring  H-­‐2】本日のまとめ
【JJUG  CCC  2014  Spring  H-­‐2】『当たり前のことだなぁ』    思った方も多いと思います  
実際にトラブルに遭遇するとググれない場合も少なくないです一刻も早く回復しなければいけないプレッシャーネット接続ができないサーバルーム【JJUG  CCC  2014  Spring  H-­‐2】
【JJUG  CCC  2014  Spring  H-­‐2】日頃から素振りをして、  すぐに実践できると万全です  
GCログとエラー時自動ヒープダンプを有効にjava -Xms?g -Xmx?g -XX:MaxMetaspaceSize=?m-Xloggc:${WILDFLY}/standalone/log/gc.log.`date +%Y%m%d%H%M%S`-XX:+PrintGCDetails -XX:+PrintGCDateStamps-XX:+UseGCLogFileRotation-XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M-XX:+HeapDumpOnOutOfMemoryError-XX:HeapDumpPath=${WILDFLY}/standalone/log/GC  ログヒープ  ダンプ【JJUG  CCC  2014  Spring  H-­‐2】
テスト環境でのOutOfMemoryエラーでは  積極的にヒープダンプを取得•  JDK6                                    ${JAVA_HOME}/bin/jmap  -­‐dump:live,format=b,file=<filename>    •  JDK7u4以降  (jmapも継続して有効)        ${JAVA_HOME/bin/jcmd  <pid>  GC.heap_dump  <filename>【JJUG  CCC  2014  Spring  H-­‐2】
商用などヒープダンプが厳しい場合はクラスヒストグラムを収集•  JDK6                                    ${JAVA_HOME}/bin/jmap  -­‐histo:live  <pid>  •  JDK7u4以降  (jmapも継続して有効)        ${JAVA_HOME/bin/jcmd  <pid>  GC.class_histogram【JJUG  CCC  2014  Spring  H-­‐2】
ヒープ情報収集には HeapStats  もおすすめ【JJUG  CCC  2014  Spring  H-­‐2】クラス別ヒープ使用量の積み上げグラフ 参照ツリー表示hjp://icedtea.classpath.org/wiki/HeapStats/jp    
アプリケーションが止まったら、  再起動する前にスレッドダンプを収集【JJUG  CCC  2014  Spring  H-­‐2】•  少なくとも1.4.2にはある    kill  -­‐3  <pid>    •  JDK5以降    ${JAVA_HOME}/bin/jstack  <pid>  •  JDK7u4以降  (kill  -­‐3  /  jstackも継続して有効)        ${JAVA_HOME/bin/jcmd  <pid>  Thread.print  
あれ?なんだか遅いな と思ったらhprofでプロファイリング【JJUG  CCC  2014  Spring  H-­‐2】java  -­‐agentlib:hprof=cpu=samples,file=<output.txt>CPU  SAMPLES  BEGIN  (total  =  145881)  Sun  May  11  12:09:05  2014  rank        self      accum          count            trace  method        1  86.56%  86.56%    126270  301470  sun.nio.ch.EPollArrayWrapper.epollWait        2    7.21%    93.77%        10521    302418  java.net.SocketInputStream.socketRead0        3    1.06%    94.83%            1552    300362  java.lang.ClassLoader.defineClass0  
【JJUG  CCC  2014  Spring  H-­‐2】#  lsof  -­‐p  <java_pid>  COMMAND      PID          USER      FD      TYPE    DEVICE  SIZE/OFF        NODE  NAME  java        14090  agetsuma    337w      REG        253,2              96    524235  /home/test/sandbox/file/0  java        14090  agetsuma    338w      REG        253,2              96    524237  /home/test/sandbox/file/1  java        14090  agetsuma    339w      REG        253,2              96    524239  /home/test/sandbox/file/2  java        14090  agetsuma    340w      REG        253,2              96    524241  /home/test/sandbox/file/3  …『too many open files』が出たら、すぐに拡張せずに lsof で事実の確認
トラブル解決には  『事実』の積み重ねが大切  【JJUG  CCC  2014  Spring  H-­‐2】OracleとJavaは、Oracle    Corpora6on    及びその子会社、関連会社の米国及びその他の国における登録商標です。  文中の社名、商品名等は各社の商標または登録商標である場合があります。

Recommended

PPTX
Java でつくる 低レイテンシ実装の技巧
PPTX
Metaspace
PDF
Garbage First Garbage Collection (G1 GC) #jjug_ccc #ccc_cd6
PDF
Javaはどのように動くのか~スライドでわかるJVMの仕組み
PDF
At least onceってぶっちゃけ問題の先送りだったよね #kafkajp
PDF
Javaコードが速く実⾏される秘密 - JITコンパイラ⼊⾨(JJUG CCC 2020 Fall講演資料)
PPTX
Kubernetesでの性能解析 ~なんとなく遅いからの脱却~(Kubernetes Meetup Tokyo #33 発表資料)
PPTX
java.lang.OutOfMemoryError #渋谷java
PDF
コンテナの作り方「Dockerは裏方で何をしているのか?」
PDF
CPU / GPU高速化セミナー!性能モデルの理論と実践:実践編
PPTX
イベント駆動プログラミングとI/O多重化
PDF
わかる!metadata.managedFields / Kubernetes Meetup Tokyo 48
PDF
例外設計における大罪
PPTX
Dockerからcontainerdへの移行
PDF
単なるキャッシュじゃないよ!?infinispanの紹介
PDF
PFN のオンプレML基盤の取り組み / オンプレML基盤 on Kubernetes 〜PFN、ヤフー〜
PDF
大規模サービスを支えるネットワークインフラの全貌
PDF
Unified JVM Logging
PDF
Linux女子部 systemd徹底入門
PPTX
第六回渋谷Java Java8のJVM監視を考える
PDF
Docker Compose 徹底解説
PDF
1076: CUDAデバッグ・プロファイリング入門
PDF
ストリーム処理を支えるキューイングシステムの選び方
PPTX
Java 9で進化する診断ツール
PPTX
大規模分散システムの現在 -- GFS, MapReduce, BigTableはどう変化したか?
PDF
YugabyteDBを使ってみよう - part2 -(NewSQL/分散SQLデータベースよろず勉強会 #2 発表資料)
PPTX
PostgreSQL開発コミュニティに参加しよう! ~2022年版~(Open Source Conference 2022 Online/Kyoto 発...
PPTX
分散システムについて語らせてくれ
PDF
Static Analysis in Go
PDF
静的解析とUIの自動生成を駆使してモバイルアプリの運用コストを大幅に下げた話

More Related Content

PPTX
Java でつくる 低レイテンシ実装の技巧
PPTX
Metaspace
PDF
Garbage First Garbage Collection (G1 GC) #jjug_ccc #ccc_cd6
PDF
Javaはどのように動くのか~スライドでわかるJVMの仕組み
PDF
At least onceってぶっちゃけ問題の先送りだったよね #kafkajp
PDF
Javaコードが速く実⾏される秘密 - JITコンパイラ⼊⾨(JJUG CCC 2020 Fall講演資料)
PPTX
Kubernetesでの性能解析 ~なんとなく遅いからの脱却~(Kubernetes Meetup Tokyo #33 発表資料)
PPTX
java.lang.OutOfMemoryError #渋谷java
Java でつくる 低レイテンシ実装の技巧
Metaspace
Garbage First Garbage Collection (G1 GC) #jjug_ccc #ccc_cd6
Javaはどのように動くのか~スライドでわかるJVMの仕組み
At least onceってぶっちゃけ問題の先送りだったよね #kafkajp
Javaコードが速く実⾏される秘密 - JITコンパイラ⼊⾨(JJUG CCC 2020 Fall講演資料)
Kubernetesでの性能解析 ~なんとなく遅いからの脱却~(Kubernetes Meetup Tokyo #33 発表資料)
java.lang.OutOfMemoryError #渋谷java

What's hot

PDF
コンテナの作り方「Dockerは裏方で何をしているのか?」
PDF
CPU / GPU高速化セミナー!性能モデルの理論と実践:実践編
PPTX
イベント駆動プログラミングとI/O多重化
PDF
わかる!metadata.managedFields / Kubernetes Meetup Tokyo 48
PDF
例外設計における大罪
PPTX
Dockerからcontainerdへの移行
PDF
単なるキャッシュじゃないよ!?infinispanの紹介
PDF
PFN のオンプレML基盤の取り組み / オンプレML基盤 on Kubernetes 〜PFN、ヤフー〜
PDF
大規模サービスを支えるネットワークインフラの全貌
PDF
Unified JVM Logging
PDF
Linux女子部 systemd徹底入門
PPTX
第六回渋谷Java Java8のJVM監視を考える
PDF
Docker Compose 徹底解説
PDF
1076: CUDAデバッグ・プロファイリング入門
PDF
ストリーム処理を支えるキューイングシステムの選び方
PPTX
Java 9で進化する診断ツール
PPTX
大規模分散システムの現在 -- GFS, MapReduce, BigTableはどう変化したか?
PDF
YugabyteDBを使ってみよう - part2 -(NewSQL/分散SQLデータベースよろず勉強会 #2 発表資料)
PPTX
PostgreSQL開発コミュニティに参加しよう! ~2022年版~(Open Source Conference 2022 Online/Kyoto 発...
PPTX
分散システムについて語らせてくれ
コンテナの作り方「Dockerは裏方で何をしているのか?」
CPU / GPU高速化セミナー!性能モデルの理論と実践:実践編
イベント駆動プログラミングとI/O多重化
わかる!metadata.managedFields / Kubernetes Meetup Tokyo 48
例外設計における大罪
Dockerからcontainerdへの移行
単なるキャッシュじゃないよ!?infinispanの紹介
PFN のオンプレML基盤の取り組み / オンプレML基盤 on Kubernetes 〜PFN、ヤフー〜
大規模サービスを支えるネットワークインフラの全貌
Unified JVM Logging
Linux女子部 systemd徹底入門
第六回渋谷Java Java8のJVM監視を考える
Docker Compose 徹底解説
1076: CUDAデバッグ・プロファイリング入門
ストリーム処理を支えるキューイングシステムの選び方
Java 9で進化する診断ツール
大規模分散システムの現在 -- GFS, MapReduce, BigTableはどう変化したか?
YugabyteDBを使ってみよう - part2 -(NewSQL/分散SQLデータベースよろず勉強会 #2 発表資料)
PostgreSQL開発コミュニティに参加しよう! ~2022年版~(Open Source Conference 2022 Online/Kyoto 発...
分散システムについて語らせてくれ

Viewers also liked

PDF
Static Analysis in Go
PDF
静的解析とUIの自動生成を駆使してモバイルアプリの運用コストを大幅に下げた話
PDF
粗探しをしてGoのコントリビューターになる方法
PDF
Mobile Apps by Pure Go with Reverse Binding
PDF
Cloud Functionsの紹介
PDF
Namespace API を用いたマルチテナント型 Web アプリの実践
PDF
Go1.8 for Google App Engine
PDF
HTTP2 RFC 発行記念祝賀会
PPTX
うしちゃん WebRTC Chat on SkyWayの開発コードw
PDF
Goにおける静的解析と製品開発への応用
PDF
GoによるiOSアプリの開発
PDF
条件式評価器の実装による管理ツールの抽象化
PDF
Go静的解析ハンズオン
PDF
goパッケージで型情報を用いたソースコード検索を実現する
PDF
Cloud functionsの紹介
PDF
メルカリ・ソウゾウでは どうGoを活用しているのか?
PDF
HTTP2 時代の Web - web over http2
PDF
Google Assistant関係のセッションまとめ
PDF
オススメの標準・準標準パッケージ20選
PPTX
WebRTC Browsers n Stacks Implementation differences
Static Analysis in Go
静的解析とUIの自動生成を駆使してモバイルアプリの運用コストを大幅に下げた話
粗探しをしてGoのコントリビューターになる方法
Mobile Apps by Pure Go with Reverse Binding
Cloud Functionsの紹介
Namespace API を用いたマルチテナント型 Web アプリの実践
Go1.8 for Google App Engine
HTTP2 RFC 発行記念祝賀会
うしちゃん WebRTC Chat on SkyWayの開発コードw
Goにおける静的解析と製品開発への応用
GoによるiOSアプリの開発
条件式評価器の実装による管理ツールの抽象化
Go静的解析ハンズオン
goパッケージで型情報を用いたソースコード検索を実現する
Cloud functionsの紹介
メルカリ・ソウゾウでは どうGoを活用しているのか?
HTTP2 時代の Web - web over http2
Google Assistant関係のセッションまとめ
オススメの標準・準標準パッケージ20選
WebRTC Browsers n Stacks Implementation differences

Similar to Javaトラブルに備えよう #jjug_ccc #ccc_h2

PDF
JDKツール使ってますか
PDF
Java SE 8におけるHotSpotの進化 [Java Day Tokyo 2014 C-2]
KEY
関ジャバ JavaOne Tokyo 2012報告会
PDF
JDK 13 New Features [MeetUp with Java Experts! @Gaienmae/Dojima 2019]
PDF
HeapStats: Introduction and Technical Preview
PDF
Oracle code one 2018 報告会概要
PPT
Javaメモリ勉強会
PDF
[豆ナイト]Java small object programming
PPTX
Java 18で入ったJVM関連の(やや細かめな)改善(JJUGナイトセミナー「Java 18 リリース記念イベント」発表資料)
PDF
インメモリーで超高速処理を実現する場合のカギ
PDF
イマドキの現場で使えるJavaライブラリ事情
PDF
Jjug springセッション
PDF
OpenJDKのコミッタってどんなことしたらなったの?解決してきた技術課題の事例から見えてくる必要な知識と技術(JJUG CCC 2023 Spring)
PDF
Spring3.1概要x di
PPTX
「書ける」から「できる」になれる! ~Javaメモリ節約ノウハウ話~
PDF
R5 3 type annotation
PPTX
Java トラブル解析支援ツール HeapStats のご紹介
PDF
TDD勉強会キックオフ for Java
PPTX
Java11へのマイグレーションガイド ~Apache Hadoopの事例~
PPT
2012年javaメモリリーク
 
JDKツール使ってますか
Java SE 8におけるHotSpotの進化 [Java Day Tokyo 2014 C-2]
関ジャバ JavaOne Tokyo 2012報告会
JDK 13 New Features [MeetUp with Java Experts! @Gaienmae/Dojima 2019]
HeapStats: Introduction and Technical Preview
Oracle code one 2018 報告会概要
Javaメモリ勉強会
[豆ナイト]Java small object programming
Java 18で入ったJVM関連の(やや細かめな)改善(JJUGナイトセミナー「Java 18 リリース記念イベント」発表資料)
インメモリーで超高速処理を実現する場合のカギ
イマドキの現場で使えるJavaライブラリ事情
Jjug springセッション
OpenJDKのコミッタってどんなことしたらなったの?解決してきた技術課題の事例から見えてくる必要な知識と技術(JJUG CCC 2023 Spring)
Spring3.1概要x di
「書ける」から「できる」になれる! ~Javaメモリ節約ノウハウ話~
R5 3 type annotation
Java トラブル解析支援ツール HeapStats のご紹介
TDD勉強会キックオフ for Java
Java11へのマイグレーションガイド ~Apache Hadoopの事例~
2012年javaメモリリーク
 

More from Norito Agetsuma

PDF
Quarkus入門
PDF
Java EEを補完する仕様 MicroProfile
PDF
CDI2.0アップデート&クックブック #JavaDayTokyo #jdt2016_4c
PPTX
JavaOne2015報告会 Java EE アップデート #j1jp
PPTX
Java EE パフォーマンスTips #glassfish_jp
PDF
Jbatch実践入門 #jdt2015
PPTX
Tomcatの実装から学ぶクラスローダリーク #渋谷Java
PPTX
Java EE8 Report
PDF
Unixカーネルの設計 7 プロセスの制御
PDF
JJUG 11月ナイトセミナー CDIをはじめよう
PDF
AeroGear & Java EE 7 で簡単プッシュ
PDF
プロになるためのJavaScript入門読書会 レジュメ
PDF
SQLアンチパターン読書会 レジュメ
PDF
JSR 352 “Batch Applications for the Java Platform”
PDF
Java Batch 仕様 (Public Review時点)
PDF
Lt agetsuma 拡大するcdi
Quarkus入門
Java EEを補完する仕様 MicroProfile
CDI2.0アップデート&クックブック #JavaDayTokyo #jdt2016_4c
JavaOne2015報告会 Java EE アップデート #j1jp
Java EE パフォーマンスTips #glassfish_jp
Jbatch実践入門 #jdt2015
Tomcatの実装から学ぶクラスローダリーク #渋谷Java
Java EE8 Report
Unixカーネルの設計 7 プロセスの制御
JJUG 11月ナイトセミナー CDIをはじめよう
AeroGear & Java EE 7 で簡単プッシュ
プロになるためのJavaScript入門読書会 レジュメ
SQLアンチパターン読書会 レジュメ
JSR 352 “Batch Applications for the Java Platform”
Java Batch 仕様 (Public Review時点)
Lt agetsuma 拡大するcdi

Javaトラブルに備えよう #jjug_ccc #ccc_h2

  • 1.
    【JJUG  CCC  2014 Spring  H-­‐2】Javaトラブルに備えよう日本Javaユーザグループ 上妻 宜人 (あげつま のりと)はてなブログ : n-agetsuma.hatenablog.com
  • 2.
    自己紹介上妻 宜人 (あげつまのりと)n  電話の裏側を作っている会社で働いていますn  Java/APサーバの社内技術サポート、トラブル解析n  Blog 『見習いプログラミング日記』【JJUG  CCC  2014  Spring  H-­‐2】
  • 3.
  • 4.
    Java  Heap  Size 6me  -­‐Xmx:  4G3GB  2GB  1GB  java.lang.OutOfMemoryError:    Java  heap  space【JJUG  CCC  2014  Spring  H-­‐2】
  • 5.
    STOP SLOW突然の無応答  or 唐突すぎるスローダウン【JJUG  CCC  2014  Spring  H-­‐2】
  • 6.
    Javaトラブルランキング  (私の感覚調べ)第1位OutOfMemoryError  の発生 (Heap、Perm、”unable  to  create  new  na6ve  Thread”)第2位スローダウン  /  タイムアウト  (SQL遅延、無限ループ、JTAタイムアウト  など)  第3位OSの設定漏れ  (“Too  many  open  files”  など)  【JJUG  CCC  2014  Spring  H-­‐2】
  • 7.
  • 8.
  • 9.
    GCログがない  クラスヒストグラムがない  ヒープダンプがない スレッドダンプがない  プロファイラがアタッチできない  APログが出てない  JMXモニタリング情報がない  【JJUG  CCC  2014  Spring  H-­‐2】
  • 10.
  • 11.
  • 12.
  • 13.
    本日のコンテンツOutOfMemoryErrorに備える  •  GCログによる過度なヒープ消費の発見 •  クラスヒストグラム  /  ヒープダンプによる解析スローダウン  /  タイムアウトに備える  •  スレッドダンプ と hprofプロファイラ  •  JTAタイムアウトの罠  OSの設定漏れに備える  •  too  many  open  files  •  unable  to  create  new  na6ve  thread  【JJUG  CCC  2014  Spring  H-­‐2】トラブル 第1位トラブル 第2位トラブル 第3位
  • 14.
    本日のコンテンツOutOfMemoryErrorに備える  •  GCログによる過度なヒープ消費の発見 •  クラスヒストグラム  /  ヒープダンプによる解析スローダウン  /  タイムアウトに備える  •  スレッドダンプ と hprofプロファイラ  •  JTAタイムアウトの罠  OSの設定漏れに備える  •  too  many  open  files  •  unable  to  create  new  na6ve  thread  【JJUG  CCC  2014  Spring  H-­‐2】トラブル 第1位トラブル 第2位トラブル 第3位
  • 15.
    【JJUG  CCC  2014 Spring  H-­‐2】Meta  SpaceOther    JVM  MemEden SurvivorOld(Tenured)Young(New)OutOfMemoryとは  :  Javaヒープ振り返りS0 S1User agetsuma =  new  User(“Norito Agetsuma”);java.lang.OutOfMemoryError:  Java  heap  spaceヒープが足りない
  • 16.
    【JJUG  CCC  2014 Spring  H-­‐2】OutOfMemoryErrorに備える【1.予兆の確認】Java  Heap  6me  -­‐Xmx:  4G3GB  2GB  1GB  『GCログの出力』【2.発生時の解析】『ヒープダンプ』『クラスヒストグラム』num    #instances    #bytes      class  name  -­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐        1              10000            250000    java.lang.String        2                  8000            200000    foo.Sample  OldNew S0 S1.hprofファイル(バイナリ形式)負荷大負荷中25.471:  [GC  (Alloca6on  Failure)      192453K-­‐>98057K(506816K),  0.1321301  secs]  負荷小
  • 17.
    GCログの出力  【JJUG  CCC 2014  Spring  H-­‐2】
  • 18.
    GCログの取得【JJUG  CCC  2014 Spring  H-­‐2】java -Xms4g –Xmx4g –XX:MaxMetaspaceSize=512m-Xloggc:${WILDFLY}/standalone/log/gc.log.`date +%Y%m%d%H%M%S`-XX:+PrintGCDetails -XX:+PrintGCDateStamps-XX:+UseGCLogFileRotation-XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M改行しないJava起動オプションにあらかじめ設定する必要がある
  • 19.
    GCログ出力の基本設定部分【JJUG  CCC  2014 Spring  H-­‐2】java -Xms4g –Xmx4g –XX:MaxMetaspaceSize=512m-Xloggc:${WILDFLY}/standalone/log/gc.log.`date +%Y%m%d%H%M%S`-XX:+PrintGCDetails -XX:+PrintGCDateStamps-XX:+UseGCLogFileRotation-XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M改行しない•  -Xloggc 出力先パスの指定•  -XX:+PrintGCDetails 詳細レベルでGCロギングする•  -XX:+PrintGCDateStamps GCログ各行に時刻を出力(デフォルトはJVM起動からの経過時間のみ)
  • 20.
    java -Xms4g –Xmx4g–XX:MaxMetaspaceSize=512m-Xloggc:${WILDFLY}/standalone/log/gc.log.`date +%Y%m%d%H%M%S`-XX:+PrintGCDetails -XX:+PrintGCDateStamps-XX:+UseGCLogFileRotation-XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M再起動時のGCログ上書きを防止する【JJUG  CCC  2014  Spring  H-­‐2】改行しないファイル名:  gc.log.20140510123200参考:  nekopの日記  GCログを上書きしないためのTips  hjp://d.hatena.ne.jp/nekop/20111017/1318812320      年 月 日 時 分 秒
  • 21.
    GCログのローテーション(JDK6u34〜/7u2〜/8)【JJUG  CCC  2014 Spring  H-­‐2】JavaVM gc.log.0  (最大10MB)サイズローテーションjava -Xms4g –Xmx4g –XX:MaxMetaspaceSize=512m-Xloggc:${WILDFLY}/standalone/log/gc.log.`date +%Y%m%d%H%M%S`-XX:+PrintGCDetails -XX:+PrintGCDateStamps-XX:+UseGCLogFileRotation-XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M改行しない
  • 22.
    JDK8でGCログも少し進化しています 【JJUG  CCC 2014  Spring  H-­‐2】Java  HotSpot(TM)  64-­‐Bit  Server  VM  (25.5-­‐b02)  for  linux-­‐amd64  JRE  (1.8.0_05-­‐b13),    built  on  Mar  18  2014  00:29:27  by  "java_re"  with  gcc  4.3.0  20080428  (Red  Hat  4.3.0-­‐8)    Memory:  4k  page,  physical  1536436k(664260k  free),  swap  3080184k(2757976k  free)    CommandLine  flags:    -­‐XX:Ini6alHeapSize=536870912  -­‐XX:MaxHeapSize=536870912    -­‐XX:+PrintGC  -­‐XX:+PrintGCDateStamps                        -­‐XX:+PrintGCDetails                                        -­‐XX:+PrintGCTimeStamps  -­‐XX:+UseCompressedClassPointers  -­‐XX:+UseCompressedOops•  バージョン/メモリ情報/コマンドライン引数のファイル先頭出力•  -­‐XX:+PrintGCCause(JDK7u40〜)  のデフォルト化25.471:  [GC  (Alloca6on  Failure)    192453K-­‐>98057K(506816K)  ...  
  • 23.
    GCViewerでログをグラフ化する【JJUG  CCC  2014 Spring  H-­‐2】hjps://github.com/chewiebug/GCViewerGC後メモリ使用量が  一定に保たれていれば正常  
  • 24.
    【JJUG  CCC  2014 Spring  H-­‐2】OutOfMemoryErrorに備える【1.予兆の確認】Java  Heap  6me  -­‐Xmx:  4G3GB  2GB  1GB  『GCログの出力』【2.発生時の解析】『ヒープダンプ』『クラスヒストグラム』num    #instances    #bytes      class  name  -­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐        1              10000            250000    java.lang.String        2                  8000            200000    foo.Sample  OldNew S0 S1.hprofファイル(バイナリ形式)負荷大負荷中25.471:  [GC  (Alloca6on  Failure)      192453K-­‐>98057K(506816K),  0.1321301  secs]  負荷小
  • 25.
    ヒープダンプの取得【JJUG  CCC  2014 Spring  H-­‐2】コマンドラインで取得  •  JDK6                                    ${JAVA_HOME}/bin/jmap  -­‐dump:live,format=b,file=<filename>    •  JDK7u4以降  (jmapも継続して有効)        ${JAVA_HOME/bin/jcmd  <pid>  GC.heap_dump  <filename>OOMエラー時に自動取得  (Java起動オプション)  •  -­‐XX:+HeapDumpOnOutOfMemoryError  •  -­‐XX:HeapDumpPath=${WILDFLY}/standalone/log/  負荷が大きいため、商用ではOOMエラー時自動取得がお勧め
  • 26.
    ヒープダンプ解析  :  Eclipse Memory  Analyzer【JJUG  CCC  2014  Spring  H-­‐2】hjp://www.eclipse.org/mat/  からダウンロード【Leak  Suspects】  ヒープ中に多いオブジェクトの表示  
  • 27.
    【JJUG  CCC  2014 Spring  H-­‐2】OutOfMemoryErrorに備える【1.予兆の確認】Java  Heap  6me  -­‐Xmx:  4G3GB  2GB  1GB  『GCログの出力』【2.発生時の解析】『ヒープダンプ』『クラスヒストグラム』num    #instances    #bytes      class  name  -­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐        1              10000            250000    java.lang.String        2                  8000            200000    foo.Sample  OldNew S0 S1.hprofファイル(バイナリ形式)負荷大負荷中25.471:  [GC  (Alloca6on  Failure)      192453K-­‐>98057K(506816K),  0.1321301  secs]  負荷小
  • 28.
    クラスヒストグラム【JJUG  CCC  2014 Spring  H-­‐2】8761:      num          #instances                  #bytes    class  name  -­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐        1:              3902054            104446080    [B        2:              1003304                64211456    org.hibernate.engine.spi.En6tyEntry        3:              1069377                60752992    [Ljava.lang.Object;        4:              1061657                53156392    [C        5:              1300009                41601968    [[B        6:              1092928                34973696    java.u6l.HashMap$Node        7:              2008549                32136784    java.lang.Integer        8:              1003304                32105728    org.hibernate.engine.internal.En6tyEntryContext        9:              1061269                25470456    java.lang.String      10:            1003304                24079296    net.agetsuma.performancetest.en6ty.Member  Javaヒープを多く占めているクラスをテキスト形式で取得 
  • 29.
    クラスヒストグラム【JJUG  CCC  2014 Spring  H-­‐2】8761:      num          #instances                  #bytes    class  name  -­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐-­‐        1:              3902054            104446080    [B        2:              1003304                64211456    org.hibernate.engine.spi.En6tyEntry        3:              1069377                60752992    [Ljava.lang.Object;        4:              1061657                53156392    [C        5:              1300009                41601968    [[B        6:              1092928                34973696    java.u6l.HashMap$Node        7:              2008549                32136784    java.lang.Integer        8:              1003304                32105728    org.hibernate.engine.internal.En6tyEntryContext        9:              1061269                25470456    java.lang.String      10:            1003304                24079296    net.agetsuma.performancetest.en6ty.Member  Javaヒープを多く占めているクラスをテキスト形式で取得 JPAエンティティの大量ロード。  JPQL直すか、ScrollableResults使うなどの対処。  
  • 30.
    クラスヒストグラムの取得【JJUG  CCC  2014 Spring  H-­‐2】コマンドラインで取得  •  JDK6                                    ${JAVA_HOME}/bin/jmap  -­‐histo:live  <pid>  •  JDK7u4以降  (jmapも継続して有効)        ${JAVA_HOME/bin/jcmd  <pid>  GC.class_histogramCTRL  +  BREAK  (Windows)  /  kill  -­‐3  で標準出力•  -­‐XX:+PrintClassHistogram  •  Windowsサービス登録されたTomcatの解析時に便利  
  • 31.
  • 32.
    よくあるOOMエラーのパターン1  【突出型】•  ある機能を動かすとOutOfMemoryErrorが発生する• 多くはDBやファイルからの大量ロードが原因【JJUG  CCC  2014  Spring  H-­‐2】青のUsedHeapが急上昇。  
  • 33.
    このパターンの解析に欲しい情報•  エラー時にどんなコードが動いていたか (アプリログ)• OutOfMemoryErrorが発生したタイミングのヒープダンプ【JJUG  CCC  2014  Spring  H-­‐2】
  • 34.
    突出型OOMエラー解決への情報収集•  Java起動オプションに普段から設定しておく•  OOMエラー発生時に自動的にヒープダンプで状況保存• 古くからあるJava起動オプション (1.4.2u12, 5u7 〜)【JJUG  CCC  2014  Spring  H-­‐2】-­‐XX:+HeapDumpOnOutOfMemoryError  -­‐XX:HeapDumpPath=${WILDFLY}/standalone/log/
  • 35.
    よくあるOOMエラーのパターン2 【じわじわ型】•  長い時間をかけてOutOfMemoryErrorに至るパターン• 再現に時間がかかる or 再現しないので厄介•  原因例: ORマッパキャッシュ/自作キャッシュ/セッション肥大化 【JJUG  CCC  2014  Spring  H-­‐2】
  • 36.
    このパターンの解析に欲しい情報•  時系列のヒープ情報 (何がじわじわ増えているのか)• 商用のみ再現するケースも多く、OutOfMemoryErrorに至る前に負荷の大きいヒープダンプを取得するのは困難【JJUG  CCC  2014  Spring  H-­‐2】なるべく軽い負荷で  時系列ヒープ情報を比較したい  
  • 37.
    【JJUG  CCC  2014 Spring  H-­‐2】じわじわ型OOMエラー解決への情報収集『定期的なクラスヒストグラムの収集』                JDK6以前 jmap  -­‐histo:live  <pid>                JDK7,8                jcmd  <pid>  GC.class_histogram  •  ヒープダンプと比較して、負荷も軽いため商用で使いやすい•  cronを利用して定期的に取得、テキストデータをグラフ化•  増加傾向クラスの利用部分のソースコードをチェック
  • 38.
    OSSツール HeapStats  で情報収集する• クラスヒストグラムを定期取得&グラフ化するのは面倒•  HeapStatsではJVMにアタッチ、低オーバヘッドで自動収集•  専用アナライザでグラフ表示も可能hjp://icedtea.classpath.org/wiki/HeapStats/jpクラス別ヒープ使用量の積み上げグラフ 参照ツリー表示
  • 39.
    java -Xms?g -Xmx?g-XX:MaxMetaspaceSize=?m-Xloggc:${WILDFLY}/standalone/log/gc.log.`date +%Y%m%d%H%M%S`-XX:+PrintGCDetails -XX:+PrintGCDateStamps-XX:+UseGCLogFileRotation-XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M-XX:+HeapDumpOnOutOfMemoryError-XX:HeapDumpPath=${WILDFLY}/standalone/log/まとめ:  OOMエラーに備えたJVMオプションGC  ログヒープ  ダンプ【JJUG  CCC  2014  Spring  H-­‐2】
  • 40.
    本日のコンテンツOutOfMemoryErrorに備える  •  GCログによる過度なヒープ消費の発見 •  クラスヒストグラム  /  ヒープダンプによる解析スローダウン  /  タイムアウトに備える  •  スレッドダンプ と hprofプロファイラ  •  JTAタイムアウトの罠  OSの設定漏れに備える  •  too  many  open  files  •  unable  to  create  new  na6ve  thread  【JJUG  CCC  2014  Spring  H-­‐2】トラブル 第1位トラブル 第2位トラブル 第3位
  • 41.
  • 42.
  • 43.
    【JJUG  CCC  2014 Spring  H-­‐2】アプリケーションが遅い、止まった。よし、スレッドダンプ取得してから、再起動で対処だ。
  • 44.
    スレッドダンプとはThread  AThread  BThread CThread  Dwait waitwaitThreadDump  1回目ThreadDump  2回目ThreadDump  3回目•  コマンド実行時のJavaスレッド状態を出力する•  その瞬間、JavaVMで何が動いていたのか調査するために使う【JJUG  CCC  2014  Spring  H-­‐2】
  • 45.
    スレッドダンプの取得【JJUG  CCC  2014 Spring  H-­‐2】•  少なくとも1.4.2にはある    kill  -­‐3  <pid>    •  JDK5以降    ${JAVA_HOME}/bin/jstack  <pid>  •  JDK7u4以降  (kill  -­‐3  /  jstackも継続して有効)        ${JAVA_HOME/bin/jcmd  <pid>  Thread.print  •  Windowsサービス登録されたTomcat画面右下の  Tomcatアイコンをクリック  
  • 46.
    スレッドダンプ出力例"default  task-­‐10"  prio=5 6d=0x00007fef5bb8d000  nid=0xb307    wai6ng  on  condi6on  [0x000000011090a000]        java.lang.Thread.State:  TIMED_WAITING  (parking)          at  sun.misc.Unsafe.park(Na6ve  Method)          -­‐  parking  to  wait  for    <0x00000007fea15470>            at  java.u6l.concurrent.locks.LockSupport.parkNanos  …          〜  省略 〜          at  org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnec6on…              at  slowweb.SlowServlet.processRequest(SlowServlet.java:44)          at  slowweb.SlowServlet.doGet(SlowServlet.java:78)          at  javax.servlet.hjp.HjpServlet.service(HjpServlet.java:687)  アプリケーション  のスタックWildFly内部  のスタック  【JJUG  CCC  2014  Spring  H-­‐2】
  • 47.
    スレッドダンプ出力例"default  task-­‐10"  prio=5 6d=0x00007fef5bb8d000  nid=0xb307    wai6ng  on  condi6on  [0x000000011090a000]        java.lang.Thread.State:  TIMED_WAITING  (parking)          at  sun.misc.Unsafe.park(Na6ve  Method)          -­‐  parking  to  wait  for    <0x00000007fea15470>            at  java.u6l.concurrent.locks.LockSupport.parkNanos  …          〜  省略 〜          at  org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnec6on…              at  slowweb.SlowServlet.processRequest(SlowServlet.java:44)          at  slowweb.SlowServlet.doGet(SlowServlet.java:78)          at  javax.servlet.hjp.HjpServlet.service(HjpServlet.java:687)  アプリケーション  のスタックWildFly内部  のスタック  データソースプール枯渇時の接続取得待ちスレッドの例【JJUG  CCC  2014  Spring  H-­‐2】
  • 48.
    可視化ツールその1  『侍』【JJUG  CCC 2014  Spring  H-­‐2】hjp://samuraism.jp/samurai/ja/index.html  からダウンロードスレッドの状態を時系列に表示するのに便利  スレッドの増加傾向や、ブロックされ具合が一目でわかる
  • 49.
    可視化ツールその2 『ThreadLogic』【JJUG  CCC 2014  Spring  H-­‐2】hjps://java.net/projects/threadlogic  からダウンロード怪しいスレッド(確認すべきスレッド)をマーキングしてくれる  特にWebLogicServer/JRockit向けが精度が高い
  • 50.
    よくある突然の無応答トラブル例•  無限ループ  • java.u6l.HashMapへのマルチスレッドアクセス  •  java.u6l.concurrent.ConcurrentHashMapに変更する  •  SQLの応答待ち  •  コネクションプール枯渇を併発して、全機能停止もある  •  SQL実行計画を確認し、インデックス付与やSQL書き直し  •  java.sql.setQueryTimeout(int  seconds)  で予防措置  【JJUG  CCC  2014  Spring  H-­‐2】[PostgreSQLの注意]  9.2からsetQueryTimeoutに対応。  〜9.1では『set  statement_6meout  to  <second>』をJDBC実行
  • 51.
  • 52.
  • 53.
    【JJUG  CCC  2014 Spring  H-­‐2】JDK付属hprofプロファイラjava  –agentlib:hprof=CPU=samples,file=<出力先指定>TRACE  301470:          sun.nio.ch.EPollArrayWrapper.epollWait(EPollArrayWrapper.java)          sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)    CPU  SAMPLES  BEGIN  (total  =  145881)  Sun  May  11  12:09:05  2014  rank        self      accum          count            trace  method        1  86.56%  86.56%    126270  301470  sun.nio.ch.EPollArrayWrapper.epollWait        2    7.21%    93.77%        10521    302418  java.net.SocketInputStream.socketRead0        3    1.06%    94.83%            1552    300362  java.lang.ClassLoader.defineClass0  •  SIGQUIT(kill  -­‐3)または、JavaVM終了時にテキスト出力
  • 54.
    【JJUG  CCC  2014 Spring  H-­‐2】hprof=CPU=samples  の特徴•  集計対象は『サンプリング時にアクティブなスレッド』のみ  •  sleep()やwait()による性能遅延は集計対象外private void sleepAndWait() … {Thread.sleep(5000);wait(5000);}private List<String> moreLoop() {return Stream.generate(() -> "slow").limit(100000).collect(toList());}【検出できるもの】  •  長いアクティブスレッド  •  ループ系性能遅延 等  【検出できないもの】  •  sleepスレッド  •  waitスレッド 等  
  • 55.
    【JJUG  CCC  2014 Spring  H-­‐2】商用での定常的収集にはJFR(有償)Java  Flight  Recorder  (JDK7u40以降)  hjp://docs.oracle.com/javase/7/docs/technotes/guides/jfr/usingjfr.html
  • 56.
  • 57.
    【JJUG  CCC  2014 Spring  H-­‐2】引っかかることの多いタイムアウトhjp://www.fancyicons.com/free-­‐icon/112/hardware-­‐icon-­‐set/free-­‐server-­‐icon-­‐png/Webサーバmod_jkDBサーバmod_jk  :  reply_6meout  (worker.proper6es)  •  APサーバからの最大応答待ち時間  (デフォルト無限)  •  タイムアウト時、ブラウザには502が返る  APサーバselect  …update…JTAトランザクションタイムアウト  •  デフォルト値  :  WildFly8  5分 /  WebLogic12c  30秒  •  タイムアウトを経過しても、止まらないことがある  
  • 58.
    【JJUG  CCC  2014 Spring  H-­‐2】JTAタイムアウト後も止まらないケースhjp://www.fancyicons.com/free-­‐icon/112/hardware-­‐icon-­‐set/free-­‐server-­‐icon-­‐png/•  応答のないSQLクエリ受信待ちの場合  •  同期ソケットI/O中にはinterrrupt()に反応しないのが要因  •  コネクションプールも浪費する要因なので厄介"default  task-­‐2”  …        java.lang.Thread.State:  RUNNABLE          at  java.net.SocketInputStream.socketRead0(Na6ve  Method)          at  java.net.SocketInputStream.read(SocketInputStream.java:150)          …            at  org.postgresql.core.v3.QueryExecutorImpl.execute  【こんなスレッドダンプには注意】
  • 59.
    【JJUG  CCC  2014 Spring  H-­‐2】WildFly8の場合はWARNログがでてきますWARN    ARJUNA012120:    Thread[…]  not  responding  to  interrupt  when  cancelling  TX  …      -­‐-­‐  worker  marked  as  zombie  and  TX  scheduled  for  mark-­‐as-­‐rollback  1.    割込みに反応しないので、ゾンビとしてマーキングWARN  ARJUNA012113:    Transac6onReaper::doCancella6ons  worker  Thread[Transac6on  Reaper  Worker  0,5,main]  missed  interrupt  when  cancelling  TX  0:ffff7f000001:-­‐87f41d4:536f3485:49    -­‐-­‐  exi6ng  as  zombie  (zombie  count  decremented  to  0)2.    SQLが返ってきたので、ゾンビスレッドを終了(ゾンビとしてマーク) (ロールバック確定)(ゾンビスレッドが終了して、残りのゾンビは0になった)
  • 60.
    【JJUG  CCC  2014 Spring  H-­‐2】SQLクエリタイムアウトを併用して対処•  JDBC  SQLタイムアウト  •  java.sql.statement.setQueryTimeout(int seconds)•  スレッド割込みではなく、キャンセル要求送信で実現  •  APサーバ機能  •  WildFly8    『set-­‐tx-­‐query-­‐6meout』の設定  (デフォルト無効)  •  WebLogic12c      『文タイムアウト』の設定  (デフォルト無限)  [再びPostgreSQLの注意]  9.2からsetQueryTimeoutに対応。  〜9.1では『set  statement_6meout  to  <second>』をJDBC実行
  • 61.
    本日のコンテンツOutOfMemoryErrorに備える  •  GCログによる過度なヒープ消費の発見 •  クラスヒストグラム  /  ヒープダンプによる解析スローダウン  /  タイムアウトに備える  •  スレッドダンプ と hprofプロファイラ  •  JTAタイムアウトの罠  OSの設定漏れに備える  •  too  many  open  files  •  unable  to  create  new  na6ve  thread  【JJUG  CCC  2014  Spring  H-­‐2】トラブル 第1位トラブル 第2位トラブル 第3位
  • 62.
    Caused  by:  java.io.FileNotFoundExcep6on: /dev/null  (Too  many  open  files)【JJUG  CCC  2014  Spring  H-­‐2】
  • 63.
    ファイルディスクリプタが足りない?init.d配下の起動スクリプトに ulimit –n65536/etc/security/limits.conf【JJUG  CCC  2014  Spring  H-­‐2】
  • 64.
  • 65.
    lsof (list openfiles) : オープン中ファイル一覧#  lsof  -­‐p  <java_pid>  COMMAND      PID          USER      FD      TYPE    DEVICE  SIZE/OFF        NODE  NAME  java        14090  agetsuma    337w      REG        253,2              96    524235  /home/test/sandbox/file/0  java        14090  agetsuma    338w      REG        253,2              96    524237  /home/test/sandbox/file/1  java        14090  agetsuma    339w      REG        253,2              96    524239  /home/test/sandbox/file/2  java        14090  agetsuma    340w      REG        253,2              96    524241  /home/test/sandbox/file/3  …『足りない』のではなく、シンプルにclose()漏れの可能性もある。事実を把握した上で対処することが大切【JJUG  CCC  2014  Spring  H-­‐2】
  • 66.
    スレッド数上限に達したときも情報収集【JJUG  CCC  2014 Spring  H-­‐2】java.lang.OutOfMemoryError  :  unable  to  create  new  thread•  いきなり /etc/security/limits.conf  の nproc  を拡大しない  •  スレッドダンプ(jcmd  <pid>  Thread.print) を取得して事実確認  •  『足りない』が原因とは限らない  •  余談ですが、このOOMエラーではヒープダンプでません
  • 67.
    【JJUG  CCC  2014 Spring  H-­‐2】本日のまとめ
  • 68.
    【JJUG  CCC  2014 Spring  H-­‐2】『当たり前のことだなぁ』    思った方も多いと思います  
  • 69.
  • 70.
    【JJUG  CCC  2014 Spring  H-­‐2】日頃から素振りをして、  すぐに実践できると万全です  
  • 71.
    GCログとエラー時自動ヒープダンプを有効にjava -Xms?g -Xmx?g-XX:MaxMetaspaceSize=?m-Xloggc:${WILDFLY}/standalone/log/gc.log.`date +%Y%m%d%H%M%S`-XX:+PrintGCDetails -XX:+PrintGCDateStamps-XX:+UseGCLogFileRotation-XX:NumberOfGCLogFiles=5 -XX:GCLogFileSize=10M-XX:+HeapDumpOnOutOfMemoryError-XX:HeapDumpPath=${WILDFLY}/standalone/log/GC  ログヒープ  ダンプ【JJUG  CCC  2014  Spring  H-­‐2】
  • 72.
    テスト環境でのOutOfMemoryエラーでは  積極的にヒープダンプを取得•  JDK6                                   ${JAVA_HOME}/bin/jmap  -­‐dump:live,format=b,file=<filename>    •  JDK7u4以降  (jmapも継続して有効)        ${JAVA_HOME/bin/jcmd  <pid>  GC.heap_dump  <filename>【JJUG  CCC  2014  Spring  H-­‐2】
  • 73.
    商用などヒープダンプが厳しい場合はクラスヒストグラムを収集•  JDK6                                   ${JAVA_HOME}/bin/jmap  -­‐histo:live  <pid>  •  JDK7u4以降  (jmapも継続して有効)        ${JAVA_HOME/bin/jcmd  <pid>  GC.class_histogram【JJUG  CCC  2014  Spring  H-­‐2】
  • 74.
    ヒープ情報収集には HeapStats  もおすすめ【JJUG CCC  2014  Spring  H-­‐2】クラス別ヒープ使用量の積み上げグラフ 参照ツリー表示hjp://icedtea.classpath.org/wiki/HeapStats/jp    
  • 75.
    アプリケーションが止まったら、  再起動する前にスレッドダンプを収集【JJUG  CCC 2014  Spring  H-­‐2】•  少なくとも1.4.2にはある    kill  -­‐3  <pid>    •  JDK5以降    ${JAVA_HOME}/bin/jstack  <pid>  •  JDK7u4以降  (kill  -­‐3  /  jstackも継続して有効)        ${JAVA_HOME/bin/jcmd  <pid>  Thread.print  
  • 76.
    あれ?なんだか遅いな と思ったらhprofでプロファイリング【JJUG  CCC 2014  Spring  H-­‐2】java  -­‐agentlib:hprof=cpu=samples,file=<output.txt>CPU  SAMPLES  BEGIN  (total  =  145881)  Sun  May  11  12:09:05  2014  rank        self      accum          count            trace  method        1  86.56%  86.56%    126270  301470  sun.nio.ch.EPollArrayWrapper.epollWait        2    7.21%    93.77%        10521    302418  java.net.SocketInputStream.socketRead0        3    1.06%    94.83%            1552    300362  java.lang.ClassLoader.defineClass0  
  • 77.
    【JJUG  CCC  2014 Spring  H-­‐2】#  lsof  -­‐p  <java_pid>  COMMAND      PID          USER      FD      TYPE    DEVICE  SIZE/OFF        NODE  NAME  java        14090  agetsuma    337w      REG        253,2              96    524235  /home/test/sandbox/file/0  java        14090  agetsuma    338w      REG        253,2              96    524237  /home/test/sandbox/file/1  java        14090  agetsuma    339w      REG        253,2              96    524239  /home/test/sandbox/file/2  java        14090  agetsuma    340w      REG        253,2              96    524241  /home/test/sandbox/file/3  …『too many open files』が出たら、すぐに拡張せずに lsof で事実の確認
  • 78.
    トラブル解決には  『事実』の積み重ねが大切  【JJUG CCC  2014  Spring  H-­‐2】OracleとJavaは、Oracle    Corpora6on    及びその子会社、関連会社の米国及びその他の国における登録商標です。  文中の社名、商品名等は各社の商標または登録商標である場合があります。

[8]ページ先頭

©2009-2025 Movatter.jp