Logstash file input inode 재사용 문제 및 해결방법

Logstash의 File input plugin을 사용해 프로듀싱할 때, 이미 프로듀싱된 로그가 다시 프로듀싱되는 문제가 종종 발생했다.

아카이빙용으로 프로듀싱하는 경우, 같은 로그가 두번 프로듀싱 되더라도 큰 문제가 없다. 하지만, 긴밀하게 연결된 파이프라인에 멱등성이 보장되지 않는 액션이 다시 프로듀싱 된다면 문제가 발생할 것이다.

이 글에서는 해당 현상의 원인과 해결 방법을 알아보자.

Logstash file input plugin

먼저 로그스태시의 input plugin 중 하나인 file input plugin에 대해 간략히 알아보자.

기본적으로 tail -0F와 비슷하게 동작하며, 옵션을 넣어 파일을 처음부터 읽을 수도 있다.

logstash가 파일을 어디까지 읽었는지는 sincedb라는 텍스트 파일을 이용해 관리하게 된다.

Sincedb

sincedb란 file input plugin이 각 파일별로 어디까지 읽었는지 기록해두는 파일이다.

sincedb는 4개(logstash 5미만 버전) 혹은 6개 컬럼으로 구성된다

$ cd /usr/share/logstash/data/plugins/inputs/file
$ cat .sincedb_e96a7e74e288b15666f4a10a4fb6a092
12 0 45 28967 1710771112.1678162 /log/generated.log
  • inode number
  • major device number
  • minor device number
  • current byte offset within file
  • last active timestamp
  • last known path

여기서 눈여겨볼 점은, inode와 byte offset이다.

Linux 파일시스템에서 파일이 제거되면, inode가 다른 파일에 할당될 수 있다. logrotate 등 로테이션이 일어나는 경우 파일 제거 직후 파일 생성이 되며, 이 경우 inode가 정확히 동일할 확률이 있다.

이 경우 file input plugin은 어떻게 동작을 할까? 코드를 확인해보자.

logstash-input-file/lib/filewatch/sincedb_collection.rb at 70aadf2510490ffafb17a11ed931dde6476f2211 · logstash-plugins/logstash-input-file
Contribute to logstash-plugins/logstash-input-file development by creating an account on GitHub.
        # the path on disk is different from discovered unassociated path but they have the same key (inode)
        # treat as a new file, a new value will be added when the file is opened
        sincedb_value.clear_watched_file
        delete(watched_file.sincedb_key)
        logger.trace? && logger.trace("associate: matched but allocated to another", :filename => watched_file.filename)

sincedb에서 같은 inode를 사용하는 파일을 찾았는데 path가 다르다면, 다른 파일로 인식하고 sincedb를 지운 뒤 다시 읽게 된다.

만약 rotate된 파일이라면? 이미 다 읽은 로그를 한번 더 읽는 문제가 발생한다.

logstash-input-file/lib/filewatch/sincedb_collection.rb at 70aadf2510490ffafb17a11ed931dde6476f2211 · logstash-plugins/logstash-input-file
Contribute to logstash-plugins/logstash-input-file development by creating an account on GitHub.
      if sincedb_value.watched_file.nil? # not associated
        if sincedb_value.path_in_sincedb.nil?
          handle_association(sincedb_value, watched_file)
          logger.trace? && logger.trace("associate: inode matched but no path in sincedb", :filename => watched_file.filename)
          return true
        end

그 다음, 동일한 inode를 사용하는 파일이 발견되었는데 sincedb에 path가 없다면, 이 경우는 같은 파일로 인식하고, 다시 읽지는 않는다. 즉 문제는 없다.

해결방법 1. file input plugin 설정 변경

1) sincedb_clean_after

일정 기간 파일에서 변경사항이 감지되지 않는다면, 해당 sincedb는 무시하는 설정이다.

기본값은 2주로 되어 있으며, 로그 rotate 주기에 맞춰서 좀 줄여주면 inode 재사용으로 인한 문제가 줄어들 수 있다

2) ignore_older

파일이 발견(discover) 되었을 때, last modified 이후 일정 기간이 지난 경우 무시되는 설정이다. 무시되었더라도 수정이 발생하면 새 데이터부터 프로듀싱된다.

기본값은 없다.

참고로 read mode에서만 동작한다.

우리 회사에선 daily rotation인 경우, sincedb_clean_after는 "4 d", ignore_older는 "2 d" 정도로 설정하고 있다.

three bugs fixed by cliffordsun · Pull Request #239 · logstash-plugins/logstash-input-file
1, The file will be processed again after logstash restart 2, all the last active timestamp in sincedb is changed after logstash restart or reload the config, it makes impact on sincedb record clea…
Fixed issue of re-reading rotated files by punxism · Pull Request #302 · logstash-plugins/logstash-input-file
This is a fix for #238 Premis logstash checks the file uniqueness using the inode number, so even if sincedb exists, it does not fully support changing the file name in all cases. In a cloud envir…

위 패치들이 file input plugin에 적용되는걸 기다리는 길도 있겠으나, 아마 안될 것 같다.

해결방법 2. Log Fingerprinting

사실은 어디까지 읽었는가에 inode를 사용하는 것 자체가 문제일 수 있다. 언제든지 inode가 재활용될 수 있으며, 서버 재부팅 또는 logstash 재시작시에도 관련 문제가 발생할 수 있다.

따라서, inode를 기록하는 대신에, 로그 파일 자체에서 핑거프린트를 계산하는 방식을 이용하는 방식이 나을 수도 있다.

File source
Collect logs from files

vector라는 log collector는 파일의 CRC 체크섬을 이용한 fingerprint를 지원한다. 물론 device + inode 방식도 지원하지만, 기본값은 checksum이다.

logstash-input-file 플러그인은 inode 재사용 관련 업데이트가 될 가망이 없기 때문에, 아예 새로운 (Rust로 만든 고성능) log collector로 넘어가는 것도 방법이다.

참고자료