Научит вас находить распространенные проблемы с производительностью Java

Обзор

Оптимизация производительности всегда была в центре внимания оптимизации серверных сервисов, но сбои производительности онлайн происходят не часто или ограничиваются бизнес-продуктами, проблем с производительностью быть не может, в том числе и у самого автора.Проблем с производительностью не так много , чтобы заранее запастись знаниями и не торопиться при возникновении проблем, в этой статье мы смоделируем несколько распространенных сбоев производительности Java, чтобы научиться их анализировать и локализовать.

Предварительные знания

Поскольку это проблема позиционирования, безусловно, необходимо использовать инструменты.Давайте сначала поймем, какие инструменты необходимы, чтобы помочь найти проблему.

высшая команда

topЭта команда является одной из наиболее часто используемых команд Linux. Она может отображать использование ЦП, использование памяти и другую системную информацию о текущем выполняющемся процессе в режиме реального времени.top -Hp pidВы можете просмотреть использование системных ресурсов потока.

команда vmstat

vmstat — это инструмент обнаружения виртуальной памяти, который указывает цикл и количество коллекций, может подсчитывать использование памяти, ЦП и подкачки, а также имеет важную общую функцию для наблюдения за переключением контекста процесса. Описание полей следующее:

r: количество процессов в очереди выполнения (когда число больше, чем количество ядер ЦП, есть заблокированные потоки)
b: количество процессов, ожидающих ввода-вывода
swpd: использовать размер виртуальной памяти
free: свободный размер физической памяти
buff: размер памяти, используемой для буферизации (память и буферы жесткого диска).
кеш: размер памяти, используемой в качестве кеша (буфер между ЦП и памятью)
si: размер, записываемый из области подкачки в память в секунду, передаваемый с диска в память.
Итак: Размер памяти, записанной в область подкачки в секунду, перенесенной из памяти на диск
bi: количество считываемых блоков в секунду
bo: количество записываемых блоков в секунду
in: Прерывания в секунду, включая прерывания часов.
cs: контекстные переключения в секунду.
us: процент времени выполнения пользовательского процесса (время пользователя)
sy: Процент времени выполнения системного процесса ядра (системное время)
wa: процент времени ожидания ввода-вывода
id: процент времени простоя

команда pidstat

pidstat является компонентом Sysstat и мощным инструментом мониторинга производительности.topиvmstatОбе команды отслеживают использование памяти, ЦП и ввода-вывода процесса, а команда pidstat может определять уровень потока.pidstatПоля переключения потоков команд описываются следующим образом:

UID: реальный ID пользователя отслеживает задачи.
TGID : идентификатор группы потоков.
TID: идентификатор потока.
cswch/s: количество активных переключений контекста, здесь — переключение потоков из-за блокировки ресурсов, например ожидания блокировки и т. д.
nvcswch/s: число пассивных переключений контекста, здесь относится к потокам переключения планирования ЦП.

команда jstack

jstack — это инструментальная команда JDK, это инструмент анализа стека потоков, наиболее часто используемая функция — использоватьjstack pidКоманда для просмотра информации о стеке потока также часто используется для устранения взаимоблокировок.

команда jstat

Он может обнаруживать работу Java-программ в режиме реального времени, включая информацию о памяти кучи и информацию о сборке мусора, и мы часто используем его для просмотра сбора мусора в программе. Общие командыjstat -gc pid. Информационные поля описываются следующим образом:

SOC: Способность к выживанию в молодом поколении (в КБ);
S1C: емкость From Survivor в молодом поколении (в КБ);
S0U: Пространство, которое в настоящее время используется To Survivor в молодом поколении (единица измерения: КБ);
S1U: Пространство, которое в настоящее время используется From Survivor в молодом поколении (единица измерения: КБ);
EC: емкость Эдема в молодом поколении (в КБ);
ЕС: Пространство, используемое в настоящее время Эдемом в молодом поколении (единица измерения: КБ);
OC: емкость старого поколения (в КБ);
OU: пространство, используемое в настоящее время старым поколением (единица измерения: КБ);
MC: емкость метапространства (единица измерения: КБ);
MU: Метапространство, используемое в настоящее время (единица КБ);
YGC: количество gcs в молодом поколении от запуска приложения до выборки;
YGCT: время (с), потраченное gc в молодом поколении от запуска приложения до времени выборки;
FGC: Количество gcs в старом возрасте (Full Gc) от запуска приложения до выборки;
FGCT: Время (с) от запуска приложения до выборки gc старого поколения (Full Gc);
GCT: общее время (с), затраченное сборщиком мусора от запуска приложения до выборки.

команда jmap

jmap также является командой инструмента JDK, которая может просматривать информацию об инициализации памяти кучи и использовании памяти кучи, а также может создавать файл дампа для подробного анализа. Команда просмотра кучи памятиjmap -heap pid.

мат памяти инструмент

Инструмент MAT (Memory Analyzer Tool) является подключаемым модулем eclipse (MAT также может использоваться отдельно), когда он анализирует файлы дампа с большой памятью, вы можете интуитивно увидеть размер памяти и количество экземпляров класса, занимаемых каждым объектом в пространство кучи, отношение ссылки на объект, использование запроса объекта OQL и может легко найти соответствующую информацию о корнях объекта GC.Адрес загрузки можно нажать здесь

Подготовка среды моделирования

В базовой среде jdk1.8 инфраструктура SpringBoot используется для написания нескольких интерфейсов для запуска сцены моделирования.Первый — для имитации ситуации полной загрузки ЦП.

ЦП заполнен

Относительно просто смоделировать полное использование ЦП, просто напишите вычисление бесконечного цикла для использования ЦП.

 		/**
     * 模拟CPU占满
     */
    @GetMapping("/cpu/loop")
    public void testCPULoop() throws InterruptedException {
        System.out.println("请求cpu死循环");
        Thread.currentThread().setName("loop-thread-cpu");
        int num = 0;
        while (true) {
            num++;
            if (num == Integer.MAX_VALUE) {
                System.out.println("reset");
            }
            num = 0;
        }

    }

Тест адреса интерфейса запросаcurl localhost:8080/cpu/loop, обнаружил, что процессор сразу взлетел до 100%

выполнивtop -Hp 32805Просмотр ситуации с потоком Java

воплощать в жизньprintf '%x' 32826Получить идентификатор потока в шестнадцатеричном формате дляdumpИнформационный запрос, результат803a. Наконец мы выполняемjstack 32805 |grep -A 20 803aчтобы увидеть подробностиdumpИнформация.

здесьdumpИнформация непосредственно указывает на проблемный метод и строку кода, которая указывает на проблему с перегрузкой ЦП.

утечка памяти

Имитация утечек памяти осуществляется с помощью объекта ThreadLocal.ThreadLocal — это приватная переменная потока, которая может быть привязана к потоку и существует на протяжении всего жизненного цикла потока. на ThreadLocalMap, а запись ThreadLocalMap наследует WeakReference, а ключ записи является инкапсуляцией WeakReference. Другими словами, ключ является слабой ссылкой, и слабая ссылка будет повторно использована после следующего GC. Если ThreadLocal не выполняет последующие операции после установки, потому что GC очистит ключ. Однако, поскольку поток все еще жив, значение не будет переработано, и в конечном итоге произойдет утечка памяти.

/**
     * 模拟内存泄漏
     */
    @GetMapping(value = "/memory/leak")
    public String leak() {
        System.out.println("模拟内存泄漏");
        ThreadLocal<Byte[]> localVariable = new ThreadLocal<Byte[]>();
        localVariable.set(new Byte[4096 * 1024]);// 为线程添加变量
        return "ok";
    }

Мы добавляем ограничение на размер памяти кучи при запуске и устанавливаем моментальный снимок стека и вывод журнала при переполнении памяти.

java -jar -Xms500m -Xmx500m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/tmp/heapdump.hprof -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:/tmp/heaplog.log analysis-demo-0.0.1-SNAPSHOT.jar

После успешного запуска мы делаем цикл 100 раз,for i in {1..500}; do curl localhost:8080/memory/leak;done, Система вернула ошибку 500 до завершения выполнения. При просмотре системного журнала произошло следующее исключение:

java.lang.OutOfMemoryError: Java heap space

мы используемjstat -gc pidКоманда, чтобы увидеть ситуацию GC программы.

Очевидно, что память переполнилась, и память кучи не освободила доступную память после 45 полных Gcs, что означает, что все объекты в текущей памяти кучи живы, на них ссылаются корни GC, и их нельзя переработать. В чем причина переполнения памяти? Просто увеличить память? Если это обычное переполнение памяти, может быть достаточно расширения памяти, но если это утечка памяти, расширенная память будет заполнена за короткое время, поэтому нам также необходимо определить, является ли это утечкой памяти. Ранее мы сохраняли файл дампа кучи, и на этот раз мы используем наш инструмент MAT для его анализа. Выбор инструмента импортаLeak Suspects Report, инструмент выдаст вам отчет о проблеме.

Здесь перечислены 4 предполагаемых проблемы с утечкой памяти, мы нажимаем на одну из них, чтобы увидеть подробности.

Здесь было указано, что память занята потоками около 50M памяти, а занятый объект — ThreadLocal. Если вы хотите подробно проанализировать его вручную, вы можете нажатьHistogram, Проверьте, кто является самым большим занятым объектом, а затем проанализируйте его отношение ссылок, чтобы определить, кто вызвал переполнение памяти.

На приведенном выше рисунке показано, что объект, который занимает больше всего памяти, представляет собой массив байтов Давайте посмотрим, ссылается ли на него корень GC и не был ли он переработан. Согласно руководству по эксплуатации в красном поле выше, результат выглядит следующим образом:

Мы обнаружили, что на массив Byte ссылается объект потока. На рисунке также указано, что GC Root объекта массива Byte является потоком, поэтому он не будет переработан. Разверните подробную информацию и обнаружите, что конечная память занятый объект является объектом ThreadLocal.объект занят. Это также согласуется с результатами, которые инструмент MAT автоматически анализирует для нас.

тупик

Взаимная блокировка приведет к исчерпанию ресурсов потока и займет память.Производительность заключается в том, что использование памяти увеличится, и процессор не обязательно будет парить (в зависимости от сцены).Если это будет прямой новый поток, это вызовет память JVM быть исчерпаны и сообщить об ошибке, что поток не может быть создан. , что также отражает преимущества использования пулов потоков.

 ExecutorService service = new ThreadPoolExecutor(4, 10,
            0, TimeUnit.SECONDS, new LinkedBlockingQueue<Runnable>(1024),
            Executors.defaultThreadFactory(),
            new ThreadPoolExecutor.AbortPolicy());
   /**
     * 模拟死锁
     */
    @GetMapping("/cpu/test")
    public String testCPU() throws InterruptedException {
        System.out.println("请求cpu");
        Object lock1 = new Object();
        Object lock2 = new Object();
        service.submit(new DeadLockThread(lock1, lock2), "deadLookThread-" + new Random().nextInt());
        service.submit(new DeadLockThread(lock2, lock1), "deadLookThread-" + new Random().nextInt());
        return "ok";
    }

public class DeadLockThread implements Runnable {
    private Object lock1;
    private Object lock2;

    public DeadLockThread(Object lock1, Object lock2) {
        this.lock1 = lock1;
        this.lock2 = lock2;
    }

    @Override
    public void run() {
        synchronized (lock2) {
            System.out.println(Thread.currentThread().getName()+"get lock2 and wait lock1");
            try {
                TimeUnit.MILLISECONDS.sleep(2000);
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
            synchronized (lock1) {
                System.out.println(Thread.currentThread().getName()+"get lock1 and lock2 ");
            }
        }
    }
}

Мы циклически запрашивали интерфейс 2000 раз и обнаружили, что через некоторое время в системе произошла ошибка журнала, а пул потоков и очередь были заполнены.Из-за стратегии, которую я выбрал для отклонения, когда очередь была заполнена, система сразу бросила исключение.

java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.FutureTask@2760298 rejected from java.util.concurrent.ThreadPoolExecutor@7ea7cd51[Running, pool size = 10, active threads = 10, queued tasks = 1024, completed tasks = 846]

пройти черезps -ef|grep javaКоманда узнает pid процесса Java и выполняетjstack pidМожет появиться информация о стеке java-потока. Здесь найдено 5 взаимоблокировок. Мы приводим только один из них. Очевидно, что потокpool-1-thread-2заблокирован0x00000000f8387d88ждать0x00000000f8387d98замок, нитьpool-1-thread-1заблокирован0x00000000f8387d98ожидание блокировки0x00000000f8387d88, что создает взаимоблокировку.

Java stack information for the threads listed above:
===================================================
"pool-1-thread-2":
        at top.luozhou.analysisdemo.controller.DeadLockThread2.run(DeadLockThread.java:30)
        - waiting to lock <0x00000000f8387d98> (a java.lang.Object)
        - locked <0x00000000f8387d88> (a java.lang.Object)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
"pool-1-thread-1":
        at top.luozhou.analysisdemo.controller.DeadLockThread1.run(DeadLockThread.java:30)
        - waiting to lock <0x00000000f8387d88> (a java.lang.Object)
        - locked <0x00000000f8387d98> (a java.lang.Object)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
          
 Found 5 deadlocks.

Частое переключение потоков

Переключение контекста приводит к тому, что много процессорного времени тратится впустую на сохранение и восстановление регистров, стеков ядра и виртуальной памяти, что приводит к общему снижению производительности системы. Когда вы заметите значительное снижение производительности системы, подумайте, не произошло ли большое количество переключений контекста потока.

 @GetMapping(value = "/thread/swap")
    public String theadSwap(int num) {
        System.out.println("模拟线程切换");
        for (int i = 0; i < num; i++) {
            new Thread(new ThreadSwap1(new AtomicInteger(0)),"thread-swap"+i).start();
        }
        return "ok";
    }
public class ThreadSwap1 implements Runnable {
    private AtomicInteger integer;

    public ThreadSwap1(AtomicInteger integer) {
        this.integer = integer;
    }

    @Override
    public void run() {
        while (true) {
            integer.addAndGet(1);
            Thread.yield(); //让出CPU资源
        }
    }
}

Здесь я создаю несколько потоков для выполнения базовой атомарной операции +1, а затем отказываюсь от ресурсов ЦП. Теоретически, ЦП будет планировать другие потоки. Мы запрашиваем интерфейс для создания 100 потоков, чтобы посмотреть, как это работает.curl localhost:8080/thread/swap?num=100. После успешного запроса интерфейса мы выполняем `vmstat 1 10, что означает, что он печатается каждую 1 секунду и 10 раз. Результаты сбора данных о переключении потоков следующие:

procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
101  0 128000 878384    908 468684    0    0     0     0 4071 8110498 14 86  0  0  0
100  0 128000 878384    908 468684    0    0     0     0 4065 8312463 15 85  0  0  0
100  0 128000 878384    908 468684    0    0     0     0 4107 8207718 14 87  0  0  0
100  0 128000 878384    908 468684    0    0     0     0 4083 8410174 14 86  0  0  0
100  0 128000 878384    908 468684    0    0     0     0 4083 8264377 14 86  0  0  0
100  0 128000 878384    908 468688    0    0     0   108 4182 8346826 14 86  0  0  0

Здесь мы ориентируемся на 4 показателя,r,cs,us,sy.

r=100, что указывает на то, что число ожидающих процессов равно 100, а поток заблокирован.

cs=более 8 миллионов, что указывает на то, что в секунду происходит более 8 миллионов переключений контекста, что является довольно большим числом.

us=14, что указывает на то, что пользовательский режим занимает 14% кванта времени процессора для обработки логики.

sy=86, что указывает на то, что состояние ядра занимает 86% ЦП, что, очевидно, выполняет переключение контекста.

мы проходимtopкоманда иtop -Hp pidГлядя на ситуацию с ЦП процесса и потока, выясняется, что ЦП потока Java заполнен, но использование ЦП потока является средним, и ни один поток не заполнен ЦП.

PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                            
 87093 root      20   0 4194788 299056  13252 S 399.7 16.1  65:34.67 java

 PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND                                                                             
 87189 root      20   0 4194788 299056  13252 R  4.7 16.1   0:41.11 java                                                                                
 87129 root      20   0 4194788 299056  13252 R  4.3 16.1   0:41.14 java                                                                                
 87130 root      20   0 4194788 299056  13252 R  4.3 16.1   0:40.51 java                                                                                
 87133 root      20   0 4194788 299056  13252 R  4.3 16.1   0:40.59 java                                                                                
 87134 root      20   0 4194788 299056  13252 R  4.3 16.1   0:40.95 java

В сочетании с вышеизложенным, ЦП пользовательского режима использует только 14%, а ЦП режима ядра занимает 86% Можно в основном судить, что переключение контекста потока программы Java вызывает проблемы с производительностью.

Мы используемpidstatКоманда для просмотра данных переключения потоков внутри процесса Java, выполнитьpidstat -p 87093 -w 1 10, собранные данные выглядят следующим образом:

11:04:30 PM   UID       TGID       TID   cswch/s nvcswch/s  Command
11:04:30 PM     0         -     87128      0.00     16.07  |__java
11:04:30 PM     0         -     87129      0.00     15.60  |__java
11:04:30 PM     0         -     87130      0.00     15.54  |__java
11:04:30 PM     0         -     87131      0.00     15.60  |__java
11:04:30 PM     0         -     87132      0.00     15.43  |__java
11:04:30 PM     0         -     87133      0.00     16.02  |__java
11:04:30 PM     0         -     87134      0.00     15.66  |__java
11:04:30 PM     0         -     87135      0.00     15.23  |__java
11:04:30 PM     0         -     87136      0.00     15.33  |__java
11:04:30 PM     0         -     87137      0.00     16.04  |__java

Согласно информации, собранной выше, мы знаем, что потоки Java переключаются примерно 15 раз в секунду, при нормальных обстоятельствах это должно быть однозначное или десятичное число. Объединив эту информацию, мы можем сделать вывод, что открыто слишком много потоков Java, что приводит к частому переключению контекста, что влияет на общую производительность.

Почему переключение контекста системы более 8 миллионов в секунду, в то время как определенный поток в Java-процессе переключается всего около 15 раз?

Переключение системного контекста делится на три ситуации:

1. Многозадачность: в многозадачной среде процесс переключается с центрального процессора на запуск другого процесса, и здесь происходит переключение контекста.

2. Обработка прерывания: при возникновении прерывания аппаратное обеспечение переключает контекст. в команде vmstat естьin

3. Переключение режима пользователя и режима ядра. Когда операционной системе необходимо переключаться между режимом пользователя и режимом ядра, требуется переключение контекста, например вызовы системных функций.

Linux поддерживает очередь готовности для каждого ЦП, сортирует активные процессы в соответствии с приоритетом и временем ожидания для ЦП, а затем выбирает процесс, которому требуется больше всего ЦП, то есть процесс с наивысшим приоритетом и наибольшим временем ожидания для запуска ЦП. . То есть в команде vmstatr.

Итак, когда процесс будет запланирован для запуска на ЦП?

После того, как процесс будет выполнен и завершен, ЦП, который он использовал ранее, будет освобожден, а затем новый процесс будет взят из очереди готовых для запуска.
Чтобы обеспечить справедливое планирование всех процессов, процессорное время делится на кванты времени, которые выделяются каждому процессу по очереди. Когда квант времени процесса исчерпан, он будет приостановлен системой и переключится на другие процессы, ожидающие запуска ЦП.
Когда системных ресурсов недостаточно, процесс может запускаться только после того, как ресурсы будут удовлетворены.В это время процесс также будет приостановлен, и система запланирует запуск других процессов.
Когда процесс активно приостанавливается через спящий режим, он также перепланируется.
Когда запущен процесс с более высоким приоритетом, чтобы обеспечить выполнение процесса с более высоким приоритетом, текущий процесс будет приостановлен и запущен процессом с более высоким приоритетом.
Когда происходит аппаратное прерывание, процесс ЦП будет приостановлен из-за прерывания и вместо этого будет выполняться процедура обслуживания прерывания в ядре.

В сочетании с нашим предыдущим контент-анализом заблокированная очередь готовности составляет около 100, а у нашего процессора всего 4 ядра.Переключение контекста, вызванное этой частью причины, может быть довольно высоким, плюс количество прерываний составляет около 4000 и вызовов системных функций. и т. д., неудивительно, что контекст переключается по системе на 8 миллионов. Переключение потока внутри Java происходит всего 15 раз, потому что поток используетThread.yield()чтобы отдать ресурсы ЦП, но ЦП может продолжать планировать поток.В это время нет переключения между потоками, поэтому количество переключений внутренних потоков не очень велико.

Суммировать

В этой статье моделируются распространенные сценарии проблем с производительностью и анализируется, как определить местонахождение CPU100%, утечек памяти, взаимоблокировок и частых проблем с переключением потоков. Чтобы анализировать проблемы, нам нужно хорошо делать две вещи: во-первых, усвоить основные принципы, а во-вторых, использовать хорошие инструменты. В этой статье также перечислены общие инструменты и команды для анализа проблем, которые могут помочь вам решить проблемы. Конечно, реальная онлайн-среда может быть очень сложной, не такой простой, как смоделированная среда, но принцип тот же, и решение задачи аналогичное.Мы сосредотачиваемся на понимании принципа, изучении и применении его, и я считают, что сложные онлайн-проблемы также могут быть гладкими.

Ссылаться на

1,linux.drop.net/full/1/ремень ослаблен...

2,linux.drop.net/full/8/vms он…

3.help.eclipse.org/2020-03/Индия…

напиши в конце

В связи с отзывами, полученными в последнее время от многих друзей, моя статья была открыта на официальном аккаунте, и я не авторизовал ее сам.Выражаю отвращение и возражение против такого рода поведения. Лично я очень надеюсь, что хорошие статьи получат широкое распространение и помогут большему количеству людей, но очень противен такой вид плагиата.Чтобы защитить авторские права на свою статью, я подал заявку на собственный паблик-аккаунт - круг друзей плотника, Я надеюсь, что заинтересованные друзья могут обратить внимание. Поскольку это новая учетная запись, в настоящее время нет контента. Он будет обновлен в будущем. Спасибо за вашу поддержку.