> ## Content Index
> Fetch the complete content index at: https://www.popit.kr/llms.txt
> Use this file to discover other available public pages before exploring further.

# Logstash로 트랜잭션 시간 구하기
- URL: https://www.popit.kr/logstash-transaction-time/
- Published: 2020-03-29T08:49:09.000Z
- Updated: 2020-03-31T13:41:01.000Z
- Author: 강 명훈
- Tags: Ruby, logstash, #팁, multiline, calculate time

[지난 글](https://www.popit.kr/logstash-filter-elapsed/)에서 elapsed 필터로 멀티 라인 구조를 갖는 하나의 트랜잭션 실행 시간을 구해봤는데 멀티 코어가 멀티 라인 로그를 나눠 처리하는 로그스태시의 동작 방식 때문에 잘 되지 않았다. 그렇다고 싱글 코어를 쓰자니 로그양이 너무 많고(..)

test.log  

```ruby
[08:00:37.410] StartJob
[08:00:39.235] EndJob
```

멀티 라인 구조를 싱글 라인으로 바꿔보자. Logstash codec 플러그인 중 [multiline](https://www.elastic.co/guide/en/logstash/current/plugins-codecs-multiline.html?ref=popit.kr#plugins-codecs-multiline)은 서로 다른 시점에 발생한 여러 개의 로그를 특정 조건으로 합쳐준다. 다음은 message 필드에 'EndJob' 패턴이 존재하면 직전(previous)에 발생한 message 필드에 추가하는 설정이며, 결과적으로 동일 트랜잭션의 시작과 끝을 알리는 로그를 하나로 합쳐준다.  

```
input {
 file {
  path => "D:/test.log"
  start_position => "beginning"
  sincedb_path => "nul"
  codec => multiline {
   pattern => "EndJob"
   what => "previous"
  }
 }
}
```

다음은 실행 결과. 멀티 코어가 줄 단위로 로그를 나눠 처리하는 과정에서 multiline 작업도 누수가 발생하지 않을까 싶었는데, 로그를 늘려도 누수는 발생하지 않는다. multiline 작업 트랜잭션이 코어 단위로 이루어지는 듯?  

```
{
"@version" => "1",
"@timestamp" => 2020-02-27T12:55:23.224Z,
"tags" => [
[0] "multiline"
],
"path" => "D:/test.log",
"message" => "[08:00:37.410] StartJob\r\n[08:00:39.235] EndJob\r",
"host" => "MHKANG"
}
```

이제 시작과 종료 시간을 추출하면 됨. 다음은 dissect 플러그인을 이용해서 시간값을 추출하는 설정.  

```
filter {
 dissect {
  mapping => { "message" => "[%{start_time}]%{}[%{end_time}]%{}" }
 }
}
```

실행 결과는 다음과 같다.  

```
{
"@version" => "1",
"@timestamp" => 2020-02-27T13:04:16.713Z,
"tags" => [
[0] "multiline"
],
"path" => "D:/test.log",
"message" => "[08:00:37.410] StartJob\r\n[08:00:39.235] EndJob\r",
"start_time" => "08:00:37.410",
"host" => "MHKANG",
"end_time" => "08:00:39.235"
}
```

이제 end\_time에서 start\_time을 빼면 됨. 그런데 추출된 필드의 데이터 유형이 '문자열'이라 산술 연산을 할 수 없다. 데이터 유형을 숫자로 바꿔주면 될까? 계산 대상은 무려 '시간'이다. 시간, 분, 초 등 시간 단위를 반영한 계산이 필요하다는 얘기.

대충 생각해도 ①각 시간 단위를 쪼갠 후 ②숫자 유형으로 바꾼 다음 ③다시 각 단위를 초 단위로 바꾸고 ④그걸 더한 필드끼리 계산하는 과정이 필요해보인다(..)

# 그런데 이 어려운 걸

ruby 플러그인이 해냄. 다음은 [Time.parse() 함수](https://www.rubyguides.com/2015/12/ruby-time/?ref=popit.kr)를 이용해서 문자 유형으로 저장된 시간 필드를 시간 유형으로 변환 후, 시간차를 계산하는 설정.  

```
filter {
 dissect {
  mapping => { "message" => "[%{start_time}]%{}[%{end_time}]%{}" }
 }
 ruby {
  code => "event.set('delay_time', Time.parse(event.get('end_time')) - Time.parse(event.get('start_time')) )"
 }
}
```

실행 결과는 다음과 같다.  

```
{
"@version" => "1",
"@timestamp" => 2020-02-27T13:19:16.779Z,
"tags" => [
[0] "multiline"
],
"path" => "D:/test.log",
"message" => "[08:00:37.410] StartJob\r\n[08:00:39.235] EndJob\r",
"start_time" => "08:00:37.410",
"delay_time" => 1.825,
"host" => "MHKANG",
"end_time" => "08:00:39.235"
}
```

ruby 만세!