1. Предпосылки

В первую очередь было установлено, что приложение для онлайн-анализа работает ненормально, и данные анализа не выводятся несколько дней подряд. Поэтому войдите в онлайн, чтобы просмотреть журнал error.log и найти:

очевидноYCYX-TaskВ этом потоке произошло переполнение памяти, из-за чего программа симулировала смерть.

Во-вторых, процесс расследования.

1. Предварительное позиционирование

jinfo

Во-первых, мы используемjinfo pidПросмотрите связанные с кучей параметры текущего jvm:

Видно, что максимальный размер кучи составляет: 4G.

jstat

Далее используем командуjstat -gcutil pid 1s 5Проверьте текущее использование кучи в течение 5 секунд:

Как и выше, новое поколение заполнено (занимает 97,33%), старое поколение также заполнено (занимает 100%), и в то же время FullGC до 967 раз!

jmap

В дополнение к команде jstat мы также можем использоватьjmap -heap pidПросмотр текущего ворса JVM:

Тогда мы используемjmap -F -histo pid | head -n 13Посмотрите первые 13 строк печати, то есть посмотрите ТОП10 крупных объектов (лучше всего ограничиться головой, иначе перечисленные объекты заполнят ваш экран, дополнительно: обязательные параметры подключения-Fправильноjmap -histo:liveэто недействительно):

Как и выше, вы можете видеть, что в дополнение к нескольким основным типам (поскольку нижние слои каждого объекта представляют собой несколько основных типов, не случайно они будут ранжироваться в верхних),java.util.HashMapиjava.util.ArrayListОчень бросается в глаза... Сначала запишите, а потом продолжайте анализировать.

Наконец, мы используем командуjmap -F -dump:file=a.bin pidСкидываем кучу и обнаруживаем, что в сброшенном файле 4.02G, что очень пугает, так что пользуйтесьtar -czvf a.tar.gz a.binУпакуйте это!

2. Углубленный анализ МАТ

Отрегулируйте максимальную память кучи MAT

Будет упакованаa.tar.gzВернитесь к локальному и разархивируйте. Однако, поскольку a.bin слишком велик, память будет переполняться при открытии MAT, поэтому отрегулируйте максимальную память кучи программного обеспечения MAT:

[ MAT根目录下的MemoryAnalyzer.ini ]
-startup
plugins/org.eclipse.equinox.launcher_1.5.0.v20180512-1130.jar
--launcher.library
plugins/org.eclipse.equinox.launcher.win32.win32.x86_64_1.1.700.v20180518-1200
-vmargs
-Xmx6g

-Xmx изменен на 6G!

MAT анализирует большие объекты

В поле зрения попадает супер-супер-супербольшой объект размером 3 ГБ, занимающий 97,25% памяти и расположенный вYCYX-TaskВ этом потоке подтверждается, что журнал ошибок YCYX-Task error.log в начале сообщает об утечке памяти. затем нажмите этоjava.lang.Object[]изDetails,Как показано ниже:

Видно, что этот массив Object действительно занимает 3 ГБ памяти, и он действительно находится внутри ArrayList, что подтверждает, что только чтоjmap -histo pid | head -n 13исключениеArrayList, а также внутреннеHashMapсоставляют!

На рисунке видно, что этот ArrayList хранит около310 000элементов, что приводит к утечке памяти. Наконец пришел к выводу, что это было связано с проблемой ArrayList в коде!

Прогулка по коду

комбинироватьerror.log日志报出的问题JAVA类,报错代码行数, а затем объединить问题应该出在一个ArrayList上, легко найти соответствующий блок кода проблемы:

  /**
	* 按照指定起止时间分析数据
	* @param beginTime 起始时间
	* @param endTime 截至时间
	*/
   @Override public void exec(String beginTime, String endTime) {
        List<Map<String, Object>> emlWithLoginList = new ArrayList<>();
        List<Map<String, Object>> emlList = new ArrayList<>();

        while (true) {
            try {
				//如果已分析到截至时间，则退出。
            	if (DateUtil.compareTime(beginTime, endTime) > 0) {
                    break;
                }

                //每次循环向前推10小时，YCYX_PERIOD=10小时
                String tmpTime=DateUtil.addHours(beginTime, YCYX_PERIOD);
                
                //1.构造请求
                BoolQueryBuilder bqb = QueryBuilders.boolQuery();
                bqb.must(QueryBuilders.rangeQuery(CREATE_TIME).gt(beginTime).lte(tmpTime));
                bqb.must(QueryBuilders.termQuery(IS_DELETE, IS_FIELD_VALUE));
                bqb.must(QueryBuilders.existsQuery(TOS));
                bqb.must(QueryBuilders.existsQuery(FROMS));
                bqb.must(QueryBuilders.existsQuery(SEND_TYPE));
                bqb.must(QueryBuilders.existsQuery(SESSION_ID));

                log.debug("emlAnalysis begin at " + beginTime + ", and end at " + lastTime);

                SearchSourceBuilder requestBuilder = new SearchSourceBuilder().query(bqb).size(PAGE_SIZE).sort(CREATE_TIME, SortOrder.ASC).fetchSource(new String[] {"*"},
                        new String[] {EML_CONTENT});

                //2.发起请求
                EsHelper.getResponseScroll(EsCluster.DEFAULT, INF_EML_INDEX, "14m", requestBuilder.toString(), result -> {
                            
                            //3.解析结果
                            EsSearchHit[] hits = result.getHits().getHits();
                            List<Map<String, Object>> loginList;
                            for (EsSearchHit hit : hits) {
                            	//将邮件Map添加到列表中
                             	Map<String, Object> emlMap = hit.getSource();
                                emlList.add(emlMap);
                                
                                //将邮件+MailLogin的Map添加到另一个列表中
                                Map<String, Object> emlWithLoginMap = new HashMap(emlMap);               
                                String sessionId = emlMap.get(SESSION_ID).toString();
                                MailLogin mailLogin = EsService.getMailLoginBySessionId(sessionId);
                                emlWithLoginMap.put("Login_Key", mailLogin );
                                emlWithLoginList.add(emlWithLoginMap);
                            }
                            return true;
                        });

                //4.A类检测逻辑
                checkDSYJEml(emlWithLoginList);
				emlWithLoginList.clear();

                //5.B类检测逻辑
                checkYCYXEml(emlList);
				emlList.clear();
                
                beginTime = tmpTime;
            } catch (Throwable e) {
                log.error("", e);
            }
        }
    }

Как видно из приведенного выше кода, Список проблем должен бытьemlWithLoginListилиemlListОдин из двух списков хранит в основном одно и то же содержимое, за исключениемemlWithLoginListВнутри элемента Map хранится дополнительный файл с именемLogin_Keyключ!

А через МАТ проверил все Ключи элементов Карты в Списке задач, и родственных обращений не нашел.Login_Key, поэтому предполагается, что список проблем должен быть такимemlList!

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

Итак, давайте сначала предположим, это потому, что данные ES за текущий период времени слишком велики?

Как видно из кода, данные, запрашиваемые ES, передаются черезCREATE_TIME(该常量值为@createtime)Для восходящего запроса данные, которые должны быть проверены в первую очередь, должны находиться в этом问题Listв начале, а затем данные проверены в问题Listконец.

Так что найди по МАТ问题ListПервый и последний элементы , то есть время начала и окончания этого запроса:

Можно увидеть, что период времени составляет примерно от 01.11.2019 16:00:00 до 02.11.2019 02:00:00! Время соответствует нашему 10-часовому периоду времени для каждого пакета запросов данных.

На рисунке показано, что, запросив этот пакет данных, программа получила 310 000 фрагментов данных!

И я пошел в Kibana, чтобы запросить объем данных за этот период времени:

Было более 20 000, совсем не на ах?

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

Обратите внимание на код в позиции на рисунке, оба списка постоянно добавляют элементы, затем выполняют соответствующую логику обнаружения и, наконец, вызываютclear()Метод очищает Список, почемуemlWithLoginListнет проблем, покаemlListНо переполнение памяти?

Тогда очевидно:

1. при выполненииcheckYCYXEml(emlList)Когда было исключение, оно будет прямо нижеcatchзахватить;
2. Так что не упадетemlList.clear()код пока не идетbeginTime = timeTime;
3. Поскольку try catch находится внутри цикла while, цикл будет продолжаться после того, как будет выброшено исключение, а также потому, что выполнение не выполняется.beginTime = timeTime, поэтому запрашиваемые данные по-прежнему являются данными предыдущего периода времени;
4. В то же время это также может объяснить, почемуemlWithLoginListНет проблем, потому что перед кодом исключения обычноclear()работать.

Тогда, если этоcheckYCYXEml(emlList)При возникновении исключения файл error.log должен быть напечатан вместе с журналом исключений через ключевое словоcheckYCYXEmlПоиск:

Конечно, было обнаружено, что исключение, сообщенное этим методом, было обнаружено, и причина была время ожидания льда. Я знаю это, потому что новое промежуточное программное обеспечение компании Company (развернуто на распределенном RPC Framework-ICE) ограничивает время ES-запроса каждого звонящего. Если он превышает указанное время, он принудительно вернет ошибку времени ожидания льда. Цель это Предотвратите нестандартные сложные высказывания от разбивающейся эс!

Согласно вышеизложенному, если причина в этом, этот код повторит запрос2019-11-01 16:00:00прибыть2019-11-02 02:00:00данных и постоянно добавляется вemlList, и, наконец, взорвать JVM!

то это в МАТ问题ListДолжно быть несколько одинаковых элементов (данные добавляются многократно).

Как это проверить?

Поскольку эти данные имеютemlkeyПоле, представляет собой уникальный первичный ключ, соответствующий данной записи в ЭП._id, так через ВСУ, по некоторым даннымemlkey, выяснить, является ли问题emlListСуществует несколько элементов с одинаковымиemlkey, что можно доказать.

Группа струн МАТ

Потому что это большие файлы сброса, поэтому запрос занимает много времени, нужно быть терпеливым -

Не по теме: Мы видим, что многие значения String одинаковы, но для хранения выделены сотни тысяч объектов String, здесь мы можем использовать Java 8-XX:+UseStringDeduplicationфункция для решения проблемы повторяющихся строк. Это приведет к этим сотням тысяч экземпляров String, но все их базовые массивы будут указывать на один и тот же массив char.

Фигура представляет собой операцию группировки для String, В настоящее время мы можем найти элемент случайным образом.emlkey, запрос:

Затем выберите запись, щелкните правой кнопкой мыши, используйтеmerge shortest paths to gc rootsможно посмотреть кратчайший путь от этих объектов до GC ROOT.. Грубо говоря, я просто хочу использовать эту функцию, чтобы проверить, какому объекту принадлежит текущая String:

Как видите, есть 32 строковых объектов, а значения являются854742740486326718e

Так почему там 32 строки, потому что каждый объект, кроме одногоemlkeyсвойства, аdocument_idАтрибут, эти два значения одинаковые, оба представляют ES_id, как показано на рисунке:

Хорошо, 16 объектов, что эквивалентно повторному запросу ES16 раз, каждый запрос равен 22221, 22221x16=355536, число в основном такое же, а не точно такое же, потому что запрос прокрутки в приведенном выше коде также имеет исключение IceTimeOut, в результате 22 221 элемент не был полностью запрошен, он будет завершен.

В конце концов, эта проблема в основном позиционируется.Репарация проста, и два метода CLEAR() перемещаются в НАКОНЕЦ после catch, то есть 100% будут вызываться, а коллега прерывания - коллега, для Icetimeout .Проблема решена.