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

Соответствующие записи журнала выглядят так

...
2018-03-12 16:18:44,070 efault task-166 gine.jdbc.internal.LogicalConnectionImpl DEBUG Obtaining JDBC connection
...
2018-03-12 16:20:23,172 efault task-166 gine.jdbc.internal.LogicalConnectionImpl DEBUG Obtained JDBC connection
...

Таким образом, если встречается шаблон «DEBUG Получение соединения JDBC», извлеките дату «2018-03-12 16:18:44,070», а когда шаблон «DEBUG Полученное соединение JDBC найдено, затем извлеките его дату и сравните две даты. Если разница более 2 секунд, то зарегистрируйтесь.

Я знаю, что это довольно сложно решить одной строкой кода, но возможно ли это сделать без написания программы?

0
Jeff Schaller 16 Май 2018 в 12:51
Что означает «затем войти, затем»?
 – 
RomanPerekhrest
16 Май 2018 в 11:44
Представляют ли ,070 и ,172 миллисекунды, и вам они небезразличны? Если «получение» происходит в 16:18:44 999, а «получение» происходит в 16:18:46 001 (разница в 1,002 секунды, но, по-видимому, 2 секунды, если вы отбросите миллисекунды), вы хотите, чтобы это сообщалось?
 – 
Jeff Schaller
16 Май 2018 в 15:52
Привет @RomanPerekhrest, мне может пригодиться любой журнал, который помогает найти строки, в которых задержка слишком велика. Например: отметка времени записи в журнале, полная запись в журнале, разница между двумя датами и т. д.
 – 
Viktor
16 Май 2018 в 18:16
Привет @JeffSchaller, просто пример того, что нужно изучить. Бывают случаи, когда разница между началом получения соединения и его получением занимает много секунд. Это похоже на узкое место, и вы хотите выяснить, почему, а не просто увеличить пул БД.
 – 
Viktor
16 Май 2018 в 18:20

2 ответа

Лучший ответ

Я бы подошел к этому с помощью awk-скрипта, приведенного ниже. Скрипт ищет строки «получение» и «получено». Типичным случаем является то, что он сначала находит «полученную» строку, а затем «полученную» строку; если «полученная» строка будет найдена первой, d1 будет сброшено или равно нулю, поэтому о ней не будет сообщено. В противном случае мы извлекаем основную часть даты (до запятой), конвертируем ее в секунды с начала эпохи, а затем снова добавляем миллисекунды. Это значение сохраняется в d1.

Как только «полученная» строка видна, ее дата вычисляется таким же образом, затем мы проверяем разницу; если это более 2 секунд, мы сообщаем об этом. В любом случае, мы затем сбрасываем d1, чтобы начать процесс заново.

Сохраните приведенное ниже в скрипт, назовите его как хотите (например, alert-jdbc.awk), затем запустите его с помощью awk -f alert-jdbc.awk < log-file-here.

Сценарию требуется утилита даты GNU для преобразования произвольных дат.

/DEBUG Obtaining JDBC connection/ {
  split($1 " " $2, dates, /,/)
  "date -d \"" dates[1]"\" +%s" | getline seconds
  d1=seconds + dates[2]/1000
}

/DEBUG Obtained JDBC connection/ {
  if (d1) {
    split($1 " " $2, dates, /,/)
    "date -d \"" dates[1]"\" +%s" | getline seconds
    d2=seconds + dates[2]/1000
    if (d2 - d1 > 2) {
        print "More than 2 seconds for: " $0
    }
    d1=0
  }
}
2
Jeff Schaller 16 Май 2018 в 16:12
Вау... абсолютно гениально! Я думаю, что Саурон действительно живет, это действительно черная магия. :) Большое спасибо, все работает отлично!
 – 
Viktor
16 Май 2018 в 19:08

Попробуй это:

Delay=$(( 
  ($(date -d "`awk '/DEBUG Obtained JDBC connection/{print $1" "$2}' file.log |
  cut -d ',' -f1 | tail -n1`" +%s)) -
  ($(date -d "`awk '/DEBUG Obtaining JDBC connection/{print $1" "$2}' file.log |
  cut -d ',' -f1 | tail -n1`" +%s)) ))
echo "$Delay Sec"

Объяснит команду, если она работает для вашего требования.

2
Siva 16 Май 2018 в 15:33
Спасибо! Я вижу только следующий вывод: 0 Sec. Я ожидал больше строк.
 – 
Viktor
16 Май 2018 в 18:13