좌충우돌 개발 블로그

기존에는 서버에 직접 로그스태시를 설치하여 카프카와 ES를 연동했다.

그래서 메모리 문제가 발생할 때 설정을 수정하고 재시작했었고 서버에 문제가 생기는 경우 로그 수집이 중단됐었다.

서버를 더 늘리면 되는데 그때마다 증설이 어려워 kubernetes를 이용해보기로 했다.

helm install -f values.yaml logstash elastic/logstash
helm upgrade -f values.yaml logstash elastic/logstash

기존에는 서버별로 수집하는 토픽을 설정했다면 쿠버네티스로 이전하면서 필터가 비슷한 경우 아니면 전부 분리할 수 있었다.

replica 수를 설정하여 파티션 만큼 로그스태시를 올릴 수 있어 속도 개선이나 장애 상황에 유연하게 대응할 수 있었다.

또한 파드별로 리소스 제한을 하여 특정 토픽에 메모리 문제가 생겨도 해당 파드만 재시작되어 다른 토픽 수집이 안됐던 것을 방지할 수 있었다.

참고 문헌

1. https://github.com/elastic/helm-charts/tree/main/logstash

배열에 넣은 로그를 개별 로그처럼 나누어서 볼 수 있도록 split 함수를 이용했었는데 메모리 문제(OOM)가 발생했었다.

그래서 해당 기능을 하는 것을 별도로 만들어서 사용하고 있었는데 다시 문제가 생겼다.

우선은 logstash.yml에서 pipeline.workers, pipeline.batch.size, pipeline.batch.delay 등을 조절하여 급한 불을 껐다.

그리고 GC도 CMS에서 G1으로 변경하여 어느 정도는 안정적으로 구동되는 걸 확인할 수 있었다.

그럼에도 메모리 사용량이 많아서 다시 검색해보니 split 함수 자체에 문제가 있었던 것을 알 수 있었다.

def register(params)
    @field = params['field']
    @target = params['target']
end

def filter(event)
    data = event.get(@field)
    event.remove(@field)
    a = []
    data.each { |x|
        e = event.clone
        e.set(@target, x)
        a << e
    }
    a
end

코드를 보면 배열에 해당하는 부분을 가져온 다음에 제거하지만 이를 JSON으로 파싱한 로그에 다시 할당하는데

이 로그에 최초 로그가 있어 이것이 배열의 수만큼 복사되어 발생한 문제였다.

JSON으로 파싱한 다음 원본 로그의 필드를 제거하고 split이 동작하도록 하여 메모리 이슈는 어느 정도 해소했다.

참고 문헌

https://discuss.elastic.co/t/how-to-split-into-multiple-events-dynamically-for-a-given-json-tried-from-various-question-in-forums/167745/9

https://github.com/logstash-plugins/logstash-filter-split/blob/main/lib/logstash/filters/split.rb#L89

로그를 쌓는데 Logstash에서 간헐적으로 OOM 에러가 발생했었다.

[ERROR][logstash.pipeline ] Exception in pipelineworker, the pipeline stopped processing new events, please check your filter configuration and restart Logstash. {:pipeline_id=>"mds", "exception"=>"Java heap space", "backtrace"=>["org.jruby.util.ByteList.<init>(ByteList.java:92)", "org.jruby.util.ByteList.dup(ByteList.java:328)", "org.jruby.util.ByteList.dup(ByteList.java:300)", "org.jruby.RubyString.doClone(RubyString.java:1346)", "org.logstash.Cloner.deep(Cloner.java:25)", "org.logstash.Cloner.deepMap(Cloner.java:65)", "org.logstash.Cloner.deep(Cloner.java:21)", "org.logstash.Event.clone(Event.java:310)", "org.logstash.ext.JrubyEventExtLibrary$RubyEvent.rubyClone(JrubyEventExtLibrary.java:147)", "org.logstash.ext.JrubyEventExtLibrary$RubyEvent.rubyClone(JrubyEventExtLibrary.java:142)", "java.base/java.lang.invoke.DirectMethodHandle$Holder.invokeSpecial(DirectMethodHandle$Holder)", "java.base/java.lang.invoke.LambdaForm$MH/0x00000008406a3440.invoke(LambdaForm$MH)", "java.base/java.lang.invoke.DelegatingMethodHandle$Holder.delegate(DelegatingMethodHandle$Holder)", "java.base/java.lang.invoke.LambdaForm$MH/0x000000084069e840.guard(LambdaForm$MH)", "java.base/java.lang.invoke.DelegatingMethodHandle$Holder.delegate(DelegatingMethodHandle$Holder)", "java.base/java.lang.invoke.LambdaForm$MH/0x000000084069e840.guard(LambdaForm$MH)", "java.base/java.lang.invoke.Invokers$Holder.linkToCallSite(Invokers$Holder)", "usr.share.logstash.vendor.bundle.jruby.$2_dot_5_dot_0.gems.logstash_minus_filter_minus_split_minus_3_dot_1_dot_7.lib.logstash.filters.split.RUBY$block$filter$1(/usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-filter-split-3.1.7/lib/logstash/filters/split.rb:88)", "java.base/java.lang.invoke.DirectMethodHandle$Holder.invokeStatic(DirectMethodHandle$Holder)", "java.base/java.lang.invoke.LambdaForm$MH/0x0000000841005040.invoke(LambdaForm$MH)", "java.base/java.lang.invoke.Invokers$Holder.invokeExact_MT(Invokers$Holder)", "org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:146)", "org.jruby.runtime.BlockBody.yield(BlockBody.java:114)", "org.jruby.runtime.Block.yield(Block.java:165)", "org.jruby.RubyArray.each(RubyArray.java:1792)", "java.base/java.lang.invoke.LambdaForm$DMH/0x000000084069ac40.invokeVirtual(LambdaForm$DMH)", "java.base/java.lang.invoke.LambdaForm$MH/0x00000008406b3440.invoke(LambdaForm$MH)", "java.base/java.lang.invoke.LambdaForm$MH/0x00000008406c2840.guardWithCatch(LambdaForm$MH)", "java.base/java.lang.invoke.LambdaForm$MH/0x00000008406c3440.invoke(LambdaForm$MH)", "java.base/java.lang.invoke.DelegatingMethodHandle$Holder.delegate(DelegatingMethodHandle$Holder)", "java.base/java.lang.invoke.LambdaForm$MH/0x0000000840674040.guard(LambdaForm$MH)", "java.base/java.lang.invoke.DelegatingMethodHandle$Holder.delegate(DelegatingMethodHandle$Holder)"], :thread=>"#<Thread:0x33a1a707 sleep>"}
[ERROR][org.logstash.Logstash ] java.lang.OutOfMemoryError: Java heap space
[WARN ][logstash.pipeline ] CAUTION: Recommended inflight events max exceeded! Logstash will run with up to 16000 events in memory in your current configuration. If your message sizes are large this may cause instability with the default heap size. Please consider setting a non-standard heap size, changing the batch size (currently 2000), or changing the number of pipeline workers (currently 8) {:pipeline_id=>"mds", :thread=>"#<Thread:0x705f801 run>"}

처음에는 JVM 옵션을 기본 설정인 -Xms1g -Xmx1g 로 하고 있어 이를 늘려서 재시작을 했다.

하지만 곧 다시 에러가 발생하면서 로그를 더이상 받지 못했다.

그래서 Kafka Input 설정 중에 max_poll_records 를 변경하면서 모니터링했다.

몇 시간 동안 잘 되는가 싶더니 곧 에러가 나더니 다시 로그 수집을 못하고 있었다.

filter에서 사용하는 부분을 검사하다 이번에 추가된 split이 문제가 있는 것 같아 구글링을 했다.

구글링을 해보니 해당 플러그인에 메모리 누수 문제가 발생하는 것 같았다.

그래서 이를 대체할 방법을 찾다가 다음과 같이 해보라는 글을 보고 따라해봤다.

def register(params)
    @field = params['field']
    @target = params['target']
end

def filter(event)
    data = event.get(@field)
    event.remove(@field)
    a = []
    data.each { |x|
        e = event.clone
        e.set(@target, x)
        a << e
    }
    a
end

json {
    source => "message"
    remove_field => [ "message" ]
}
ruby {
    path => '/my/path/splitData.rb'
    script_params => { field => "data" target => "data" }
}

split을 변경한 이후로 메모리 누수로 인하여 로그 수집이 중단되는 현상이 나오진 않았다.

참고 문헌

1. https://github.com/logstash-plugins/logstash-filter-split/issues/35

2. https://discuss.elastic.co/t/how-to-split-into-multiple-events-dynamically-for-a-given-json-tried-from-various-question-in-forums/167745/11

ELK를 구성하여 로그를 잘 쌓고 있었는데 어느 날 로그가 수집되고 있지 않았다.

원인을 찾기 위해 Logstash의 로그(/var/log/logstash/logstash-plain.log)를 열어봤다.

[INFO ][logstash.outputs.elasticsearch] retrying failed action with response code: 403 ({"type"=>"cluster_block_exception", "reason"=>"blocked by: [FORBIDDEN/12/index read-only / allow delete (api)];"})

위의 로그가 많이 있어 검색을 해보니 ElasticSearch에 용량이 부족할 경우

Kibana에서 인덱스를 읽기 전용으로 변경한다는 내용이었다.

ElasticSearch의 저장 공간 사용량을 확인해보니 90% 넘게 차있었다.

이를 해결하기 위해 우선은 다음과 같이 쿼리를 날려 로그를 다시 수집할 수 있도록 했다.

PUT http://ElasticSearch:9200/_all/_settings
{
  "index": {
    "blocks": {
      "read_only_allow_delete": "false"
    }
  }
}

그리고 인덱스를 지워 용량을 확보해 로그들을 다시 쌓을 수 있었다.

참고 문헌

1. https://dev-yeon.tistory.com/12