Разбираем логи

| Нет трекбэков

Бот записывает массу информации в лог-файлы. Давайте разберемся как ее можно анализировать и использовать.

Все файлы логов хранятся в папке log. Они делятся на несколько категорий:

  • system.log - в этот файл попадает вся информация о боте, за исключением логов http-сервера. Может использоваться для просмотра цельной картины происходящего в боте. Но анализ может быть затруднен из-за избыточной информации в этом файле.
  • talk.log - этот файл предназначен для хранения только разговоров чата, я постарался отфильтровать отсюда все лишнее. При настройках по умолчанию файлы этого лога создаются за каждый день и хранятся всегда.
  • error.log - очень важный файл, сюда попадает информация из потока ошибок бота. Анализ может затруднить тот факт, что здесь не видно источник ошибки - после какого сообщения она произошла. Для анализа причин необходимо использовать system.log.
  • flood.log - сюда попадают сообщения, которые бот посчитал флудом. Обычно в них нет ничего страшного - это повторы или очень частые сообщения в чате. Но если вы видите большой поток повторяющихся сообщений с нескольких номеров - на это стоит обратить внимание, скорее всего ваш бот подвергся флуд-атаке. Для решения проблемы необходимо выделить уникальные номера из потока сообщений и добавить их в игнор-лист (файл idnore.txt). Сделать это можно разными способами. Лично я предпочитаю парсить логи с помощью Excel, а потом выделять уникальные номера Access.
  • http.log - содержит информацию о http-запросах к вашей веб-админке. Здесь вы можете увидеть попытки несанкционированного доступа к вашему боту. Но прошу обратить внимание, что эти логи могут содержать важную информацию о паролях и других настройках вашего бота. Не передавайте этот лог просто так незнакомым  людям.

Давайте теперь рассмотрим самое важное - лог ошибок. Как правило, при обработки исключения в боте используется конструкция:

        try{
            // некоторый текст программы
        }catch (Exception ex){
            ex.printStackTrace();
            // какое-то сообщение пользователю чата об ошибке
        }        

В результате ошибки происходит запись стека вызовов программы в поток ошибок, а следовательно и в лог-файл. Сообщение обычно выглядит следующим образом:

08.02.2009 18:45:50 [ERROR] - com.mysql.jdbc.exceptions.jdbc4.MySQLSyntaxErrorException: Table 'mychat.rooms' doesn't exist
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at sun.reflect.NativeConstructorAccessorImpl.newInstance(Unknown Source)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at java.lang.reflect.Constructor.newInstance(Unknown Source)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at com.mysql.jdbc.Util.handleNewInstance(Util.java:406)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at com.mysql.jdbc.Util.getInstance(Util.java:381)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1031)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:957)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3376)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3308)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1837)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1961)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2537)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2466)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at com.mysql.jdbc.StatementImpl.executeQuery(StatementImpl.java:1383)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at ru.jimbot.modules.chat.RoomWork.fillCash(RoomWork.java:59)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at ru.jimbot.modules.chat.UserWork.<init>(UserWork.java:84)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at ru.jimbot.modules.chat.ChatServer.start(ChatServer.java:71)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at ru.jimbot.Manager.start(Manager.java:196)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at ru.jimbot.modules.http.MainPage.srvs_start(MainPage.java:261)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at java.lang.reflect.Method.invoke(Unknown Source)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at ru.jimbot.modules.http.MainPage.doGetOrPost(MainPage.java:742)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at ru.jimbot.modules.http.MainPage.doGet(MainPage.java:718)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:740)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at org.garret.httpserver.JHttpSession.session(JHttpSession.java:154)
08.02.2009 18:45:50 [ERROR] -  
08.02.2009 18:45:50 [ERROR] - 	at org.garret.httpserver.JHttpSession.run(JHttpSession.java:64)

В начале блока сообщений мы видим собственно ошибку "Table 'mychat.rooms' doesn't exist", а далее идет содержимое стека вызовов. Оно как правило не интересно. Но если причина ошибки вам непонятна - смотрите место вызова, произошедшее непосредственно в боте. Так в данном случае мы видим что ошибка произошла: "at ru.jimbot.modules.chat.RoomWork.fillCash(RoomWork.java:59)" - файл RoomWork.java, строка 59. Это первая строчка, качающаяся исходников непосредственно нашего бота, а не сторонней библиотеки. Что находится в этой строке можно поглядеть в исходных текстах бота. Проанализировав эту информацию часто можно определить причину произошедшей ошибки. В рассмотренном выше случае все понятно из текста ошибки - отсутствует таблица rooms в базе данных.

Что еще нужно знать о логах? Для создания логов используется стандартная и широко распространенная библиотека log4j. Описание ее возможностей вы можете посмотреть на официальном сайте. Начиная с версии 0.4.0 настройки логирования выведены во внешний файл конфигурации: lib\log4j.properties. В нем вы можете настроитьтакие параметры как: размер файлов логов, количество архивных файлов, способ обозначения названий архивных файлов.

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

Нет трекбэков

URL для трекбэков: http://jimbot.ru/cgi-bin/mt-tb.cgi/23

Loading

Об этой записи

Сообщение опубликовано 11.03.2009 16:37. Автор — Spec.

Предыдущая запись — Как запустить (использовать) скрипт?

Следующая запись — JimBot 0.4.0 pre-release 3

Смотрите новые записи на главной странице или загляните в архив, где есть ссылки на все сообщения.

Хостинг для чата

Рейтинг@Mail.ru службы мониторинга серверов