Upgrade to Pro — share decks privately, control downloads, hide ads and more …

Я знаю почему тормозит ваша Java

aragozin
September 06, 2017

Я знаю почему тормозит ваша Java

aragozin

September 06, 2017
Tweet

More Decks by aragozin

Other Decks in Programming

Transcript

  1. Я знаю, почему
    тормозит ваша
    Алексей Рагозин
    [email protected]
    Java

    View full-size slide

  2. После месяцев упорного труда
    с кучей нового функционала
    оттестированное и проверенное
    ваше приложение в эксплуатации!
    И всё идёт хорошо, пока …

    View full-size slide

  3. Пользователи начинают жаловаться на тормоза
    Логи забиваются ошибками
    Руководство начитает нервничать
    И тебе нужно срочно
    всё исправить!

    View full-size slide

  4. Что может пойти нетак?
    Server
    Browser
    Application
    Database

    View full-size slide

  5. Что может пойти нетак?
    Server
    Browser
    Application
    Database
    Caching
    JavaScript
    HTTP
    Network Network
    SQL performance
    CPU Memory / Swapping
    Disk IO Virtualization

    View full-size slide

  6. Три правила
    Правило 1. Формулировка цели
     Какова цель оптимизации?
     Как будет измерен результат?
     Формулировка должна быть понятна всем сторонам!
    Бизнес транзакция ≠ Страница
    Бизнес транзакция ≠ SQL транзакция
    Страница ≠ HTTP запрос
    HTTP запрос ≠ SQL транзакция

    View full-size slide

  7. Три правила
    Правило 2. Система – Чёрный ящик
     Вы не можете знать, что происходит внутри системы!
     Не важно, кто писал код, и как он выглядит
     Нужно опираться на факты, а не на суждения
     Любую гипотезу нужно проверять

    View full-size slide

  8. Три правила
    Три типа информации, которую даёт профайлер
     Ложь – неверно истолкованные данные
     Откровенная ложь – неверно измеренные результаты
     Статистика – данные, которые помогают решить проблему

    View full-size slide

  9. Три правила
    Правило 3. “Научный” подход
     Перепроверяйте результаты
     Не оптимизируйте результаты профайлера
     Используйте статистику

    View full-size slide

  10. Дерево анализа
    Поддерево сервера приложений
    Server CPU
    consumption
    What application
    threads are doing?
    Low
    Application CPU
    consumption
    High
    Low
    Server CPU
    starvation?
    High
    Which threads
    consume CPU?
    JVM
    threads
    Application
    threads
    GC?
    Profiling
    CPU hotspots
    Sleep
    Wait
    IO
    Contention?
    Who is
    blocking us?
    ?

    View full-size slide

  11. Классы проблем в Java коде
    Вычислительные (CPU Bound)
     Вычислительная сложность
     “Голодание” нитей (CPU starvation)
    Многопоточность
     Соревнование за ресурсы (contention)
     Ожидание выделенного потока
     Взаимные блокировки потоков (deadlocks)
    Память и сборка мусора
     Слишком часты сборки мусора
     Ненормально большие GC паузы
     Частые полные сборки (Full GC)

    View full-size slide

  12. Профайлеры и Профайлеры
    Instrumentation built into JVM
    Java Visual VM
    JVMTI
    JMX
    Byte Code Instrumentation

    View full-size slide

  13. JVisualVM
    Предварительный осмотр

    View full-size slide

  14. JProfiler
    Предварительный осмотр

    View full-size slide

  15. SJK ttop
    > java –jar sjk.jar ttop -p 12345 -n 20 -o CPU
    2016-11-07T00:09:50.091+0400 Process summary
    process cpu=268.35%
    application cpu=244.42% (user=222.50% sys=21.93%)
    other: cpu=23.93%
    GC cpu=6.28% (young=1.62%, old=4.66%)
    heap allocation rate 1218mb/s
    safe point rate: 1.5 (events/s) avg. safe point pause: 43.24ms
    safe point sync time: 0.03% processing time: 6.39% (wallclock time)
    [000056] user=17.45% sys= 0.62% alloc= 106mb/s - hz._hzInstance_2_dev.generic-operation.thread-0
    [000094] user=17.76% sys= 0.31% alloc= 113mb/s - hz._hzInstance_3_dev.generic-operation.thread-1
    [000093] user=16.83% sys= 0.00% alloc= 111mb/s - hz._hzInstance_3_dev.generic-operation.thread-0
    [000020] user=16.06% sys= 0.15% alloc= 108mb/s - hz._hzInstance_1_dev.generic-operation.thread-0
    [000021] user=15.44% sys= 0.15% alloc= 110mb/s - hz._hzInstance_1_dev.generic-operation.thread-1
    [000057] user=14.36% sys= 0.00% alloc= 110mb/s - hz._hzInstance_2_dev.generic-operation.thread-1
    [000105] user=13.59% sys= 0.00% alloc= 72mb/s - hz._hzInstance_3_dev.cached.thread-1
    [000079] user=13.43% sys= 0.15% alloc= 67mb/s - hz._hzInstance_2_dev.cached.thread-3
    [000042] user=10.96% sys= 0.62% alloc= 65mb/s - hz._hzInstance_1_dev.cached.thread-2
    [000174] user=10.65% sys= 0.31% alloc= 66mb/s - hz._hzInstance_3_dev.cached.thread-7
    [000123] user= 8.96% sys= 0.00% alloc= 55mb/s - hz._hzInstance_4_dev.response
    [000129] user= 7.72% sys= 0.31% alloc= 21mb/s - hz._hzInstance_4_dev.generic-operation.thread-0
    [000168] user= 6.95% sys= 0.62% alloc= 33mb/s - hz._hzInstance_1_dev.cached.thread-6
    [000178] user= 7.57% sys= 0.00% alloc= 32mb/s - hz._hzInstance_2_dev.cached.thread-9
    [000166] user= 6.48% sys= 0.46% alloc= 33mb/s - hz._hzInstance_1_dev.cached.thread-5
    [000130] user= 6.02% sys= 0.62% alloc= 20mb/s - hz._hzInstance_4_dev.generic-operation.thread-1
    https://github.com/aragozin/jvm-tools
    Предварительный осмотр

    View full-size slide

  16. Mission Control
    Предварительный осмотр

    View full-size slide

  17. Техники профилирования
    Сэмплирование
    Анализ случайной выборки событий
     Сэмплирование стеков потоков
     Сэмплирование аллокации памяти
    Трассировка
    Анализ всех событий определённого типа
     Трассировка вызовов методов
     Трассировка операций определённого класса

    View full-size slide

  18. Техники профилирования
    Сэмплирование
    Анализ случайной выборки событий
     Сэмплирование стеков потоков
     Сэмплирование аллокации памяти
    Трассировка
    Анализ всех событий определённого типа
     Трассировка вызовов методов
     Трассировка операций определённого класса

    View full-size slide

  19. Сэмплирование потоков
    Task.run()
    wait() process()
    getBody()
    read() parse()
    handle()
    load()
    read()
    Time
    encode()
    wait() process()
    getBody()
    read() parse()
    handle()
    load()
    read()
    encode()
    wait() process()
    getBody()
    read() parse()
    handle()
    encode()
    10 Task.run
    7
    3
    process()
    4 handle()
    3 encode()
    2 ...
    1 ...
    1 load()
    geBody()
    2
    1 read()
    parse()
    1
    3 wait()
    ...

    View full-size slide

  20. JVisualVM
    Анализ результатов сэмплирования

    View full-size slide

  21. Mission Control
    Анализ результатов сэмплирования

    View full-size slide

  22. JProfiler
    Анализ результатов сэмплирования

    View full-size slide

  23. flame graph with SJK
    Анализ результатов сэмплирования
    https://github.com/aragozin/jvm-tools

    View full-size slide

  24. JEE world example
    JBoss + Seam + Hibernate

    View full-size slide

  25. Анализ результатов сэмплирования
    Command
    sjk ssa -f tracedump.std --categorize -tf **.CoyoteAdapter.service -nc
    JDBC=**.jdbc
    Hibernate=org.hibernate
    "Facelets compile=com.sun.faces.facelets.compiler.Compiler.compile"
    "Seam bijection=org.jboss.seam.**.aroundInvoke/!**.proceed"
    JSF.execute=com.sun.faces.lifecycle.LifecycleImpl.execute
    JSF.render=com.sun.faces.lifecycle.LifecycleImpl.render
    Other=**
    Report
    Total samples 2732050 100.00%
    JDBC 405439 14.84%
    Hibernate 802932 29.39%
    Facelets compile 395784 14.49%
    Seam bijection 385491 14.11%
    JSF.execute 290355 10.63%
    JSF.render 297868 10.90%
    Other 154181 5.64% 0.00%
    10.00%
    20.00%
    30.00%
    40.00%
    50.00%
    60.00%
    70.00%
    80.00%
    90.00%
    100.00%
    Time
    Other
    JSF.render
    JSF.execute
    Seam bijection
    Facelets compile
    Hibernate
    JDBC
    Excel
    Категоризация по шаблонам

    View full-size slide

  26. Ограничения сэмплирования
    Сильные стороны
     Малые накладные расходы
     Не нужна конфигурация
     Позволяет обнаружить
     Данные сравнимы между запусками и версиями кода
    Недостатки
     Ограниченная точность измерений
     Нельзя оценить реальное время вызова/операции
     Детализация ограничена структурой кода

    View full-size slide

  27. Инструментация и трассировка
    Инструментация
     Профайлер меняет выполняемый код приложения налету
     Существенные накладные расходы
     Параметры вызова могут быть включены в трассировку
    Трассировка методов
     Время и число вызовов метода
     Временная линия выполнения кода

    View full-size slide

  28. https://github.com/chewiebug/GCViewer
    GC Viewer
    Динамика сборки мусора

    View full-size slide

  29. -XX:InitialTenuringThreshold=8
    Initial value for tenuring threshold (number of collections
    before object will be promoted to old space)
    -XX:+UseTLAB Use thread local allocation blocks in eden
    -XX:MaxTenuringThreshold=15
    Max value for tenuring threshold
    -XX:PretenureSizeThreshold=2m Max object size
    allowed to be allocated in young space (large objects will be
    allocated directly in old space). Thread local allocation
    bypasses this check, so if TLAB is large enough object
    exciding size threshold still may be allocated in young space.
    -XX:+AlwaysTenure Promote all objects surviving
    young collection immediately to tenured space
    (equivalent of -XX:MaxTenuringThreshold=0)
    -XX:+NeverTenure Objects from young space
    will never get promoted to tenured space unless survivor
    space is not enough to keep them
    -XX:+ResizeTLAB Let JVM resize TLABs per thread
    -XX:TLABSize=1m Initial size of thread’s TLAB
    -XX:MinTLABSize=64k Min size of TLAB
    -XX:+UseCMSInitiatingOccupancyOnly
    Only use predefined occupancy as only criterion for starting
    a CMS collection (disable adaptive behaviour)
    -XX:CMSInitiatingOccupancyFraction=70
    Percentage CMS generation occupancy to start a CMS cycle.
    A negative value means that CMSTriggerRatio is used.
    -XX:CMSBootstrapOccupancy=50
    Percentage CMS generation occupancy at which to initiate
    CMS collection for bootstrapping collection stats.
    -XX:CMSTriggerRatio=70
    Percentage of MinHeapFreeRatio in CMS generation that is
    allocated before a CMS collection cycle commences.
    -XX:CMSWaitDuration=30000
    Once CMS collection is triggered, it will wait for next young
    collection to perform initial mark right after. This parameter
    specifies how long CMS can wait for young collection
    -XX:+CMSScavengeBeforeRemark
    Force young collection before remark phase
    -XX:+CMSScheduleRemarkEdenSizeThreshold
    If Eden used is below this value, don't try to schedule remark
    -XX:CMSScheduleRemarkEdenPenetration=20
    Eden occupancy % at which to try and schedule remark pause
    -XX:CMSScheduleRemarkSamplingRatio=4
    Start sampling Eden top at least before young generation occupancy
    reaches 1/ of the size at which we plan to schedule remark
    -XX:+CMSIncrementalMode
    Enable incremental CMS mode. Incremental mode was meant for
    severs with small number of CPU, but may be used on multicore
    servers to benefit from more conservative initiation strategy.
    -XX:+CMSClassUnloadingEnabled
    If not enabled, CMS will not clean permanent space. You
    may need to enable it for containers such as JEE or OSGi.
    -XX:ConcGCThreads=2
    Number of parallel threads used for concurrent phase.
    -XX:ParallelGCThreads=16
    Number of parallel threads used for stop-the-world phases.
    -XX:+DisableExplicitGC
    JVM will ignore application calls to System.gc()
    -XX:+ExplicitGCInvokesConcurrent
    Let System.gc() trigger concurrent collection instead of full GC
    -XX:+ExplicitGCInvokesConcurrentAndUnloadsClasses
    Same as above but also triggers permanent space collection.
    -XX:PrintCMSStatistics=1
    Print additional CMS statistics. Very verbose if n=2.
    -XX:+PrintCMSInitiationStatistics
    Print CMS initiation details
    -XX:+CMSDumpAtPromotionFailure
    Dump useful information about the state of the CMS old
    generation upon a promotion failure
    -XX:+CMSPrintChunksInDump (with optin above)
    Add more detailed information about the free chunks
    -XX:+CMSPrintObjectsInDump (with optin above)
    Add more detailed information about the allocated objects
    by Alexey Ragozin – http://blog.ragozin.info
    HotSpot JVM options cheatsheet
    Young space tenuring
    Thread local allocation
    Parallel processing
    -XX:+CMSOldPLABMin=16 -XX:+CMSOldPLABMax=1024
    Min and max size of CMS gen PLAB caches per worker per block size
    CMS initiating options
    CMS Stop-the-World pauses tuning
    Misc CMS options
    CMS Diagnostic options
    - Options for “deterministic” CMS, they disable some heuristics and
    require careful validation
    Concurrent Mark Sweep (CMS)
    All concrete numbers in JVM options in this card are for illustrational purposes only!
    -XX:+ParallelRefProcEnabled Enable parallel
    processing of references during GC pause
    -XX:SoftRefLRUPolicyMSPerMB=1000 Factor
    for calculating soft reference TTL based on free heap size
    -XX:OnOutOfMemoryError=… Command to be executed
    in case of out of memory.
    E.g. “kill -9 %p” on Unix or “taskkill /F /PID %p” on Windows.
    -XX:G1HeapRegionSize=32m Size of heap region
    -XX:MaxGCPauseMillis=500 Target GC pause duration.
    G1 is not deterministic, so no guaranties for GC pause to satisfy this limit.
    -XX:G1ReservePercent=10 Percentage of heap to keep free.
    Reserved memory is used as last resort to avoid promotion failure.
    -XX:G1ConfidencePercent=50 Confidence level
    for MMU/pause prediction
    -XX:G1HeapWastePercent=10 If garbage level is below
    threshold, G1 will not attempt to reclaim memory further
    -XX:G1MixedGCCountTarget=8 Target number of mixed
    collections after a marking cycle
    -XX:InitiatingHeapOccupancyPercent=45
    Percentage of (entire) heap occupancy to trigger concurrent GC
    Garbage First (G1)
    -XX:+CMSParallelRemarkEnabled
    Whether parallel remark is enabled (enabled by default)
    -XX:+CMSParallelSurvivorRemarkEnabled
    Whether parallel remark of survivor space enabled,
    effective only with option above (enabled by default)
    -XX:+CMSConcurrentMTEnabled
    Use multiple threads for concurrent phases.
    CMS Concurrency options
    -XX:+CMSParallelInitialMarkEnabled
    Whether parallel initial mark is enabled (enabled by default)
    -XX:CMSTriggerInterval=60000 Periodically triggers_
    CMS collection. Useful for deterministic object finalization.
    http://blog.ragozin.info/2016/10/hotspot-jvm-garbage-collection-options.html
    Young collector Old collectior JVM Flags
    Serial (DefNew)
    Parallel scavenge (PSYoungGen)
    Parallel scavenge (PSYoungGen)
    Parallel (ParNew)
    Serial (DefNew)
    Parallel (ParNew)
    Serial Mark Sweep Compact
    Serial Mark Sweep Compact (PSOldGen)
    Parallel Mark Sweep Compact (ParOldGen)
    Concurrent Mark Sweep
    Concurrent Mark Sweep
    Serial Mark Sweep Compact
    -XX:+UseSerialGC
    -XX:+UseParallelGC
    -XX:+UseParallelOldGC
    -XX:+UseParNewGC
    -XX:-UseParNewGC1 -XX:+UseConcMarkSweepGC
    -XX:+UseParNewGC -XX:+UseConcMarkSweepGC
    -XX:+UseG1GC
    Garbage First (G1)
    1 - Notice minus before UseParNewGC, which is explicitly disables parallel mode
    -verbose:gc or -XX:+PrintGC Print basic GC info
    -XX:+PrintGCDetails Print more details GC info
    -XX:+PrintGCTimeStamps Print timestamps for each GC
    event (seconds count from start of JVM)
    -XX:+PrintGCDateStamps Print date stamps at garbage
    collection events: 2011-09-08T14:20:29.557+0400: [GC...
    -Xloggc: Redirects GC output to a file instead of console
    -XX:+PrintTLAB Print TLAB allocation statistics
    -XX:+PrintReferenceGC Print times for special
    (weak, JNI, etc) reference processing during STW pause
    -XX:+PrintJNIGCStalls Reports if GC is waiting for
    native code to unpin object in memory
    -XX:+PrintClassHistogramAfterFullGC
    Prints class histogram after full GC
    -XX:+PrintClassHistogramBeforeFullGC
    Prints class histogram before full GC
    -XX:+UseGCLogFileRotation Enable GC log rotation
    -XX:GCLogFileSize=512m Size threshold for GC log file
    -XX:NumberOfGCLogFiles=5 Number GC log files
    -XX:+PrintGCCause Add cause of GC in log
    -XX:+PrintHeapAtGC Print heap details on GC
    -XX:+PrintAdaptiveSizePolicy
    Print young space sizing decisions
    -XX:+PrintHeapAtSIGBREAK Print heap details on signal
    -XX:+PrintPromotionFailure
    Print additional information for promotion failure
    -XX:+PrintPLAB Print survivor PLAB details
    -XX:+PrintOldPLAB Print old space PLAB details
    -XX:+PrintGCTaskTimeStamps Print timestamps for
    individual GC worker thread tasks (very verbose)
    -XX:+PrintGCApplicationStoppedTime
    Print summary after each JVM safepoint (including non-GC)
    -XX:+PrintGCApplicationConcurrentTime
    Print time for each concurrent phase of GC
    GC Log rotation
    More logging options
    -XX:+PrintTenuringDistribution Print detailed
    demography of young space after each collection
    GC log detail options
    -Xms256m or -XX:InitialHeapSize=256m
    Initial size of JVM heap (young + old)
    -Xmx2g or -XX:MaxHeapSize=2g
    Max size of JVM heap (young + old)
    -XX:NewSize=64m
    -XX:MaxNewSize=64m
    Absolute (initial and max) size of
    young space (Eden + 2 Survivours)
    -XX:NewRatio=3 Alternative way to specify size
    of young space. Sets ratio of young vs old space
    (e.g. -XX:NewRatio=2 means that young space will be 2 time
    smaller than old space, i.e. 1/3 of heap size).
    -XX:SurvivorRatio=15 Sets size of single survivor space
    relative to Eden space size
    (e.g. -XX:NewSize=64m -XX:SurvivorRatio=6 means that each
    Survivor space will be 8m and Eden will be 48m).
    -XX:MetaspaceSize=512m
    -XX:MaxMetaspaceSize=1g
    Initial and max size of
    JVM’s metaspace space
    -Xss256k (size in bytes) or
    -XX:ThreadStackSize=256 (size in Kbytes)
    Thread stack size
    -XX:MaxDirectMemorySize=2g Maximum amount
    of memory available for NIO off-heap byte buffers
    - Highly recommended option
    Memory sizing options
    by Alexey Ragozin – http://blog.ragozin.info
    Available combinations of garbage collection algorithms in HotSpot JVM
    - Highly recommended option
    HotSpot JVM options cheatsheet
    All concrete numbers in JVM options in this card are for illustrational purposes only!
    Java Process Memory
    JVM Memory
    Java Heap
    Non-JVM Memory
    (native libraries)
    Non-Heap
    Young Gen
    Old Gen
    Eden
    Survivor 0
    Survivor 1
    Thread Stacks
    Metaspace
    Compressed Class Space
    Code Cache
    NIO Direct Buffers
    Other JVM Memmory
    -Xms/-Xmx
    -XX:CompressedClassSpaceSize=1g Memory reserved
    for compressed class space (64bit only)
    -XX:InitialCodeCacheSize=256m
    -XX:ReservedCodeCacheSize=512m
    Initial size and max
    size of code cache area
    Настройка сборка мусора

    View full-size slide

  30. Динамика сборки мусора
    Mission Control

    View full-size slide

  31. Mission Control
    Сэмплирование аллокации памяти

    View full-size slide

  32. Flight Recorder Vs. Visual VM
    Method sampling
    Method tracing
     Generic
     IO
    Allocation sampling
    Heap dump inspection
    Startup profiling
    Continuous profiling
    Flight Recorder
    Only Java code
    Low overhead
    No
    Built-in events
    Low overhead
    No
    Yes
    May require license
    Visual VM
    On Safepoints
    High overhead
    Yes
    -
    High overhead
    Yes
    No
    No
    Java Visual VM

    View full-size slide

  33. Заключение
     Профайлер не скажет вам, где проблема
     Три правила
     JVisual VM и Mission Control – эффективные
    инструменты при правильном использовании
     Сохраняйте спокойствие!

    View full-size slide

  34. KEEP CALM
    AND MAKE YOUR JAVA FAST AGAIN
    Алексей Рагозин
    [email protected]
    http://blog.ragozin.info

    View full-size slide