in_tcp: a parser error drops the other lines in the same read and closes the connection

オープン
  • 何か問題がありますか？
#5,629 コメント 0 件 リアクション 0 件 担当者 0 名 GitHub で見る

メンテナーはふだん 1 日以内に返信

まだ誰も着手していません。

評価

難易度
3/5
見積もり時間
1〜2日
初心者へのやさしさ
64/100
issue の種類
バグ
明瞭さ
明確に書かれている
活発さ
活発
技術スタック
ruby
領域
backend, networking

調査の方向性

Start in lib/fluent/plugin/in_tcp.rb at the parser calls around lines 144 and 195, then read how warn_pattern_not_matched handles invalid lines. Reproduce with the three-line TCP write from the issue and the supplied JSON parser configuration. Done means a bad line is warned about and dropped while valid lines before and after it are emitted and the connection stays open.

索引モデルが issue の本文から書いたものです。

説明

bug
Describe the bug

in_tcp does not rescue errors from @parser.parse(msg) for each line. When the parser raises, the error goes up to the server helper. The helper logs unexpected error on reading data and closes the connection.

  • With batch emit (the default), the lines already parsed in the same read are not emitted. The lines after the bad line are lost too.
  • With single emit (<extract> with tag_key), the lines before the bad line are emitted. The lines after it are lost.

A parser can raise on a normal input. For example, the json parser with time_format raises ParserError when the time field does not match the format. So one bad line from a client can drop its valid lines.

https://github.com/fluent/fluentd/blob/e7d3c3e4/lib/fluent/plugin/in_tcp.rb#L144
https://github.com/fluent/fluentd/blob/e7d3c3e4/lib/fluent/plugin/in_tcp.rb#L195

To Reproduce

Run Fluentd with the configuration below. Then send these three lines in one write:

{"k":"1"}
{"time":"bad","k":"2"}
{"k":"3"}

ruby -rsocket -e 'TCPSocket.open("127.0.0.1", 5170) { |s| s.write(%Q({"k":"1"}\n{"time":"bad","k":"2"}\n{"k":"3"}\n)); sleep 1 }'

Results on master (e7d3c3e4):

  • Batch emit: no event is emitted. {"k":"1"} and {"k":"3"} are lost. The server closes the connection.
  • Single emit (add <extract> with tag_key tag): {"k":"1"} is emitted. {"k":"3"} is lost. The server closes the connection.
Expected behavior

Only the bad line is dropped, with a warning. This is how in_tcp handles a line that does not match the pattern (pattern not matched). The other lines are emitted, and the connection stays open.

Your Environment
- Fluentd version: master (e7d3c3e4). v1.20.1 and v1.19.4 have the same code (not run).
- Package version: -
- Operating system: Linux
- Kernel version: -
Your Configuration
<source>
  @type tcp
  port 5170
  bind 127.0.0.1
  tag test
  <parse>
    @type json
    time_key time
    time_format %Y-%m-%dT%H:%M:%S
  </parse>
</source>
<match test>
  @type stdout
</match>
Your Error Log
[error]: unexpected error on reading data host="127.0.0.1" port=39444 error_class=Fluent::Plugin::Parser::ParserError error="invalid time format: value = bad, error_class = ArgumentError, error = string doesn't match"
  [error]: lib/fluent/plugin/parser.rb:195:in 'Fluent::Plugin::Parser#parse_time'
  [error]: lib/fluent/plugin/parser_json.rb:70:in 'Fluent::Plugin::JSONParser#parse'
  [error]: lib/fluent/plugin/in_tcp.rb:195:in 'block in Fluent::Plugin::TcpInput#start'
  [error]: lib/fluent/plugin_helper/server.rb:661:in 'on_read_with_connection'

No test: {...} line is printed with batch emit.

Additional context

A possible fix is to rescue the error for each line. Then log a warning in the same way as warn_pattern_not_matched (truncated as in #5592), and go on to the next line.

主要言語
Ruby
スター
13.6k
フォーク
1.4k
平均マージ
17時間 28分
マージ済み PR（30日）
66

環境構築

はじめの一歩

  1. issue を最後まで読み、次にプロジェクトのコントリビューションガイドを読みます。
  2. 着手することを issue にコメントします — 二人が同じ作業をするのを防げます。
  3. リポジトリをフォークし、ブランチを切って変更します。
  4. issue 番号を参照したプルリクエストを送ります。

fluent/fluentd のほかの issue

fluent/fluentd の issue をすべて見る

似ている issue

Ruby の issue をもっと見る

新しい issue をメールで受け取る

初心者向けの GitHub issue を短くまとめたダイジェスト。