При использовании подхода из данного решения парсинг файлов будет не нужен. При изменении формата логирования или появлении новых сообщений не нужно поддерживать большой набор регулярок. Будем перехватывать вызовы методов error, warn, info, debug, trace логера и отправлять данные сразу в elasticsearch. С этим нам поможет аспектно-ориентированное программирование!
Скринкаст вы можете посмотреть в конце статьи.
Надеюсь, что вам будет интересно узнать как с помощью аспектов написанных в виде скрипта и конфигурации можно работать с elasticsearch клиентом, gson сериализатором и параметрами перехваченного метода в jvm.
Подопытной программой остается SonarQube, как и в статьях про hawt.io/h2, логирование jdbc и CRaSH-ssh. Подробнее про процесс установки и конфигурирования сонара и агента виртуальной машины можете почитать в публикации про hawt.io/h2.
На этот раз будем использовать параметры запуска jvm сонара:
sonar.web.javaAdditionalOpts=-javaagent:aspectj-scripting-1.0-agent.jar -Dorg.aspectj.weaver.loadtime.configuration=config:file:es.xml
И для работы примера необходимо скачать jvm агент aspectj-scripting и файл конфигурации es.xml:
<?xml version="1.0" encoding="UTF-8" standalone="yes"?>
<configuration>
<aspects>
<name>com.github.igorsuhorukov.Loging</name>
<type>AROUND</type>
<pointcut>call(* org.slf4j.Logger.error(..)) || call(* org.slf4j.Logger.warn(..)) || call(* org.slf4j.Logger.info(..)) || call(* org.slf4j.Logger.debug(..)) || call(* org.slf4j.Logger.trace(..))</pointcut>
<process>
<expression>
res = joinPoint.proceed();
log = new java.util.HashMap();
log.put("level", joinPoint.getSignature().getName());
log.put("srcf", joinPoint.getSourceLocation().getFileName().substring(0, joinPoint.getSourceLocation().getFileName().length()-5));
log.put("srcl", joinPoint.getSourceLocation().getLine());
if(joinPoint.getArgs()!=null && joinPoint.getArgs().?length>0){
log.put("message", joinPoint.getArgs()[0].?toString());
if(joinPoint.getArgs().length > 1){
params = new java.util.HashMap();
for(i=1; i < joinPoint.getArgs().length;i++){
if(joinPoint.getArgs()[i]!=null){
if(joinPoint.getArgs()[i].class.getName().equals("[Ljava.lang.Object;")){
for(j=0; j < joinPoint.getArgs()[i].length;j++){
if( (joinPoint.getArgs()[i])[j] !=null){
params.put(i+"."+j,(joinPoint.getArgs()[i])[j].toString());
}
}
} else {
params.put(i,joinPoint.getArgs()[i].toString());
}
}
}
log.put("params", params);
}
}
log.put("host", reportHost); log.put("pid", pid);
log.put("@version", 1);
localDate = new java.util.Date();
lock.lock();
log.put("@timestamp", dateFormat.format(localDate));
index = "logstash-" + logstashFormat.format(localDate);
lock.unlock();
logSource = gson.toJson(log);
client.index(client.prepareIndex(index, "logs").setSource(logSource).request());
res;
</expression></process>
</aspects>
<globalContext>
<artifacts>
<artifact>com.google.code.gson:gson:2.3.1</artifact>
<classRefs>
<variable>GsonBuilder</variable>
<className>com.google.gson.GsonBuilder</className>
</classRefs>
</artifacts>
<artifacts>
<artifact>org.elasticsearch:elasticsearch:1.1.1</artifact>
<classRefs>
<variable>NodeBuilder</variable>
<className>org.elasticsearch.node.NodeBuilder</className>
</classRefs>
</artifacts>
<init>
<expression>
import java.text.SimpleDateFormat;
import java.util.TimeZone;
import java.util.concurrent.locks.ReentrantLock;
reportHost = java.net.InetAddress.getLocalHost().getHostName();
pid = java.lang.management.ManagementFactory.getRuntimeMXBean().getName().split("@")[0];
gson = new GsonBuilder().create();
dateFormat = new SimpleDateFormat("yyyy-MM-dd'T'HH:mm:ss.SSS'Z'");
dateFormat.setTimeZone(TimeZone.getTimeZone("UTC"));
logstashFormat = new SimpleDateFormat("yyyy.MM.dd");
logstashFormat.setTimeZone(TimeZone.getTimeZone("UTC"));
lock = new ReentrantLock();
client = NodeBuilder.nodeBuilder().clusterName("distributed_app").data(false).client(true).node().client();
</expression>
</init>
</globalContext>
</configuration>
Для всех точек вызова из программы методов error, warn, info, debug, trace интерфейса org.slf4j.Logger, вызывается аспект, в котором мы создаем HashMap log и заполняем параметрами контекста вызова: файла класса «srcf» и строки в нем «srcl», указываем уровень логирования «level», имя хоста «host», идентификатора процесса «pid», временем вызова логера "@timestamp", а так же шаблон текста сообщения и отдельно в Map «params» сохраняем его параметры. Все это синхронно с вызовом сериализуется в json и отправляется в индекс с именем «logstash-» + дата вызова. Классы для форматирования даты и времени, а также клиент для elasticsearch создаются при старте приложения в блоке глобальной инициализации аспектов globalContext.
Классы elasticsearch загружаются из maven репозитария по координатам org.elasticsearch:elasticsearch:1.1.1, а json сериализатора по координатам com.google.code.gson:gson:2.3.1.
Клиент из аспекта при старте по мультикаст протоколу пытается найти кластер elasticsearch с именем «distributed_app»
Перед запуском нашего клиента обязательно запустим кластер elasticsearch сервера, состоящий из одного процесса:
package org.github.suhorukov;
import org.elasticsearch.common.settings.ImmutableSettings;
import org.elasticsearch.node.Node;
import org.elasticsearch.node.NodeBuilder;
import java.io.InputStream;
import java.net.URL;
import java.util.concurrent.TimeUnit;
public class ElasticsearchServer {
public static void main(String[] args) throws Exception{
String template;
try(InputStream templateStream = new URL("https://raw.githubusercontent.com/logstash-plugins/logstash-output-elasticsearch/master/lib/logstash/outputs/elasticsearch/elasticsearch-template.json").openStream()){
template = new String(sun.misc.IOUtils.readFully(templateStream, -1, true));
}
Node elasticsearchServer = NodeBuilder.nodeBuilder().settings(ImmutableSettings.settingsBuilder().put("http.cors.enabled","true")).clusterName("distributed_app").data(true).build();
Node node = elasticsearchServer.start();
node.client().admin().indices().preparePutTemplate("logstash").setSource(template).get();
Thread.sleep(TimeUnit.HOURS.toMillis(5));
}
}
Для компиляции и работы этого класса необходима зависимость:
<dependency>
<groupId>org.elasticsearch</groupId>
<artifactId>elasticsearch</artifactId>
<version>1.1.1</version>
</dependency>
Для просмотра логов скачаем старую сборку kibana 3.1.3, которая может работать без веб сервера. Отредактируем файл config.js
elasticsearch: "http://127.0.0.1:9200"Запускаем сонар
./bin/linux-x86-64/sonar.sh startи наблюдаем в браузере как в процессе работы SonarQube в kibana отображаются события этой системы
Про какие примеры с применением аспектов вам интересно было бы почитать? Предлагайте!
Комментарии (14)
relgames
18.09.2015 14:36Будем перехватывать вызовы методов error, warn, info, debug, trace логера и отправлять данные сразу в elasticsearch.
Делали так. Бывали случаи, когда приложение падало еще до загрузки такого отправляльщика. Или даже до загрузки Java — например, один раз Java снесли случайно.
Сейчас все логи пишем прямо в stdout, и на каждое приложение запускаем log-courier, который по сети отправляет логи на центральный сервер.
igor_suhorukov
19.09.2015 01:42Верное замечание!
Часто логи приложения разделяют — лог jvm + stdout + stderr в один файл, а application logger в отдельные роллинг файлы.
Решение что описал, я как вы верно заметили, подходит только для логов java приложения.
dstarcev
Только сегодня занимались написанием регулярок под logstash.
Совпадение? Не думаю.Хотя мысль об отправке логов напрямую в эластик была, но отказались от такого варианта.
Подход с регулярками нам нравится тем, что:
1. Все сервисы умеют писать на диск. Значит, что логи можно читать из любого источника. Например, сегодня подцепились к access и error логам nginx, а также к логам одного из наших приложений. Так же планируем читать логи множества сторонних сервисов, которые мы используем, и которые могут писать логи только на диск или иное unix устройство.
2. Смущает возможная деградация производительности при записи приложением напрямую в эластик. У нас сложное приложение и достаточно много логов, и мы переживаем за время отклика.
3. Нас регулярками не запугать :)
igor_suhorukov
С первым пунктом не поспоришь — универсальнее не бывает, если читать человеку
Пункт 2 основан на реальных опасениях… Можно решить за счет асинхронной публикации. И ведь активно используют в проектах syslog ng и т.п.
Я вас отлично понимаю) по поводу пункта 3.
dstarcev
Я имел в виду, что читать будет logstash, чтобы передать в elasticsearch. Человек будет применяться уже непосредственно для работы с красивой kibana :).
Насчет асинхронности соглашусь, можно решить, навскидку, через простую очередь в памяти процесса с периодической bulk отсылкой в эластик. Но это же надо кодить, а логи на диске уже лежат готовые и ждут своего часа. В общем, у нас пока такой быстрый старт получился, с регулярками и минимальными затратами. (Если честно, я пока в некоторой эйфории пребываю от новых для меня и неожиданно крутых инструментов) Может быть, потом случится настроение убрать лишнее звено и запилить elasticsearch адаптер для log4net. Скорее всего даже готовый есть.
За видео спасибо, поглядим на досуге.
Еще вопрос есть: почему решили применить аспекты, а не написать реализацию логера для записи в эластик и ее указать в приложении?
igor_suhorukov
Удачи вам в интересной технологии и теме!
Вопрос с аспектами в точку) Подобное решение могу порекомендовать только если нет доступа к исходному проекту, но есть доступ к JAVA_OPTS процесса для передачи агента и конфигурации. Т.е. ни исходное приложение, ни его конфигурация специально не изменяются для публикации логов в elasticsearch
Lelik13a
Разворачивал я систему логирования logstash+elasticsearch, куда сыпалось много разношёрстых логов. На большом промежутке времени оно стабильно так и не работало. То logstash в ступор уйдёт, то elasticsearch. Logstash приходилось просто перегружать, elasticsearch чистить базу логов, иначе система деградирует. Собирал логи, по наивности используя tcp, в том числе и с веб-серверов — в результате, при ступоре logstash, в ступор впадали и все, кто пытались отправить логи по tcp. Пришлось всё переделывать на udp. Пробовал разные варианты настройки и того и другого, с сжатием и без.
В общем, как-то стабильности и уверенности в работе связка не внушила.
Если есть положительный пример использования, с десятками источников логов и базой в десятки гигабайт поделитесь опытом.
igor_suhorukov
У нас все стабильно работало на logstash+es. Elasticsearch работал в кластере на 6 хостах и индекс был шардирован — самое большое преимущество ES «из коробки». Индексы просто не хранил больше чем за последние N дней ( реализовал как свой CleanupRiver тогда — описано на слайде «Удаление индексов старше заданной даты», стр.21 )
С logstash и регулярками были проблемы с тем что ПО постоянно менялось и конфиг logstash надо было постоянно поддерживать в актуальном состоянии, а еще досаждало multiline не послылал последнее событие из файла, пока не приходила новая строчка лога.
Главная проблема, которая была — иногда заканчивалось место на диске, если приложение генерировало нетипично много логов в какой либо из последних дней и саппорт комманда не реагировала на это.
Lelik13a
У меня был один es, возможно тут грабли и затаились. Но логов хотелось хранить долго, хотя бы пол года. Чистить по расписанию — не проблема, проблема в том, что даже эти пол-года не влазили.
А logstash да, править приходилось частенько. Надеюсь, когда устоится, проект будет интереснее.
igor_suhorukov
Скрещиваю за ваш проект пальцы!) Главная сила elastic search в горизонтальном масштабировании и в сети достаточно документации по дизайну систем с ним и тюнингу
relgames
У нас 6 машин, на каждой запущено несколько десятков микросервисов. Сервисы пишут в stdout, который перенаправляется в log-courier, который отправляет логи на центральный logstash, который пишет в elasticsearch.
Были проблемы с тем, что на центральном сервере кончалось место, но это решилось очисткой старых индексов по крону.
Индексы, кстати, лучше всего по часам: logstash-%{+YYYY.MM.dd.HH}
igor_suhorukov
Интересное решение!
Вы рассматривали использование lumberjack?
Видимо у вас очень много записей, раз партиционируете по часам
dstarcev
Почему выбрали схему с log-courier и централизованным logstash? Смущает единая точка отказа, как следствие централизации.
relgames
мимо… удалил…