Repository navigation
Conversation
…n string parser With `parser_engine string`, `parse_rfc5424` ended STRUCTURED-DATA at the first `] `. RFC 5424 section 6.3.3 requires `]` in a PARAM-VALUE to be escaped as `\]`, so a valid message such as `... ID [x@1 a="b\] c"] msg` put part of the structured data into `message`. Skip `] ` when the `]` is preceded by `\`, as the regexp parser does with `(?<!\\)\]`. Fixes fluent#5587 Signed-off-by: YuMin Kim <yuminkim.dev@gmail.com>
Signed-off-by: YuMin Kim <yuminkim.dev@gmail.com>
Watson1978
left a comment
There was a problem hiding this comment.
Thanks for the fix. I checked ec56def on Linux with Ruby 4.0.9. On master (bd36a9e), four string rows of the new test fail. With this change, all rows pass, and the PR merges cleanly with the current master. For the inputs in the new test, the string parser now finds the same boundary between the structured data and the message as the regexp parser.
I found one problem. The new loop can take quadratic time on UTF-8 input. Please see the inline comment.
About the backslash removal in extradata: please keep the current behavior in this PR. Changing it would change the extradata that users get today. It would affect users who monitor their logs in the current format. That goes beyond a bug fix, and we could not backport it. So we keep the current behavior.
| else | ||
| start = cursor | ||
| i = text.index('] '.freeze, cursor) | ||
| i = text.index('] '.freeze, i + 1) while i && text[i - 1] == '\\'.freeze # skip escaped ']' (RFC 5424 6.3.3) |
There was a problem hiding this comment.
MUST: This loop can take quadratic time. When the string is UTF-8 and has non-ASCII characters, text.index and text[] take character offsets, and each call counts the characters from the start of the string. So each escaped ] makes the parser scan the text before it again.
I measured parse with parser_engine string on a 96 KB line. Its structured data is [x@32473 a=" + あ\] repeated 16,000 times + "], followed by msg.
- master: 0.08 ms
- this PR: 1.27 seconds
Through in_tail with encoding UTF-8, one 288 KB line like this took about 11 seconds. filter_parser on a UTF-8 field is affected too. The normal in_syslog receive path is not, because it passes binary strings to the parser.
Please keep these two points when you fix it:
- The time should grow linearly with the input.
- A UTF-8 string with an invalid byte in MSG should not raise. For example, this PR returns the message
m\xFFsgfor... ID [x@1 a="b\] c"] m\xFFsg. A regexp search such astext.index(/(?<!\\)\] /, i)raisesArgumentErrorfor it, so please do not use one. Please add this input to the new test.
This version walks the characters once after the first escaped ]. It returns the same results as this PR.
| i = text.index('] '.freeze, i + 1) while i && text[i - 1] == '\\'.freeze # skip escaped ']' (RFC 5424 6.3.3) | |
| if i && text[i - 1] == '\\'.freeze # skip escaped ']' (RFC 5424 6.3.3) | |
| offset = i | |
| previous = '\\'.freeze | |
| candidate = false | |
| i = nil | |
| text.slice(offset, text.length).each_char do |char| | |
| if candidate && char == SPLIT_CHAR | |
| i = offset - 1 | |
| break | |
| end | |
| candidate = char == ']'.freeze && previous != '\\'.freeze | |
| previous = char | |
| offset += 1 | |
| end | |
| end |
With this change, the 96 KB line takes 3.6 ms, input without an escaped ] is as fast as before, and all tests in test_parser_syslog.rb pass.
There was a problem hiding this comment.
Thank you for the review and the suggestion. I applied it as is in c6c42e3. That commit also adds ... ID [x@1 a="b\] c"] m\xFFsg to the new test, with the expected message m\xFFsg. I added it for the string engine only, because the regexp engine already raises ArgumentError for this input on master.
The backslash removal in extradata is unchanged. This PR does not touch the tr! line.
I measured parse with parser_engine string on your 96 KB line on macOS arm64 with Ruby 3.4.12. The machine was busy (load average about 70), so the absolute times are probably higher than on an idle machine. The numbers are the minimum of 20 runs, except ec56def, which is the minimum of 3.
- master (af25743): 0.10 ms. It ends the structured data at the first escaped
], so it does less work. - ec56def: 1.73 s
- c6c42e3: 12.5 ms
With c6c42e3, the time grows linearly with the number of escaped ]. For 4,000 / 8,000 / 16,000 / 32,000 / 64,000 repetitions, it took 2.9 / 6.1 / 12.5 / 24.6 / 50.3 ms. For a line of the same size without an escaped ], master took 0.36 ms and c6c42e3 took 0.38 ms.
I also compared ec56def and c6c42e3 on 20,000 random structured data strings. They contained \, ], [, ", spaces, あ and \xFF. The output was the same for every input.
Executed locally:
test/plugin/test_parser_syslog.rbandtest/plugin/test_in_syslog.rb, on this branch and on this branch merged with master af25743. All pass.rubocop lib/fluent/plugin/parser_syslog.rb test/plugin/test_parser_syslog.rb, with rubocop 1.91.0 and rubocop-performance 1.26.1. No offenses.
Not executed: the in_tail and filter_parser paths, Linux, Windows, and Ruby 4.0.
One more thing I noticed: tr! raises ArgumentError when the structured data has an invalid byte. This also happens on master. Because the string parser now ends the structured data at the right place, some invalid bytes that master put into the message are now in extradata. In the random comparison, 29 of the 20,000 inputs parse on master but raise at tr! with this PR. All of them are malformed: an invalid byte inside the structured data. I left tr! unchanged, as you asked. I can open a separate issue for it if that helps.
The loop that skipped escaped `]` called `text.index` and `text[]` for each escaped `] `. On UTF-8 strings with non-ASCII characters, each of them counts characters from the start of the string, so a line with many escaped `] ` took quadratic time. After the first escaped `]`, walk the remaining characters once instead. Do not use a regexp search, which raises ArgumentError when MSG has an invalid byte. Suggested-by: Watson1978 in fluent#5591 (comment) Signed-off-by: YuMin Kim <yuminkim.dev@gmail.com>
Which issue(s) this PR fixes:
Fixes #5587
What this PR does / why we need it:
With
parser_engine string,parse_rfc5424ends STRUCTURED-DATA at the first]. It does not check whether that]is escaped. RFC 5424 section 6.3.3 requires]in a PARAM-VALUE to be escaped as\], so a message like this is valid:On master, the string parser returns extradata
[x@1 a="b]and messagec"] msg.This PR skips a
]when the]comes right after a\. The regexp parser does the same with(?<!\\)\]. With this change, the string parser returns the whole structured data as extradata andmsgas message.The issue's Expected section says:
With this PR, extradata holds the whole structured data and message is
msg. However, the extradata is still not byte-for-byte what the regexp parser returns. That is a separate, pre-existing difference: since the string parser was added in 3226d94, it has removed every backslash from extradata, while the regexp parser keeps them. For the input above:extradatamessageparser_engine string(this PR)[x@1 a="b] c"]msgparser_engine regexp[x@1 a="b\] c"]msgThat difference already exists on master for other escapes. For example,
[x@1 a="b\"c"]gives[x@1 a="b"c"]with the string parser and[x@1 a="b\"c"]with the regexp parser (observed locally). I left the backslash removal as it is, because removing it would change the output for\"and\\as well. I can remove it in a follow-up if you want.Like the regexp parser, this PR only looks at the one character before
]. Two inputs with an escaped backslash are covered by tests:[x@1 a="b\\"] msg, a value that ends with an escaped backslash. The character before]is", so both engines end the structured data there, before and after this change.[x@1 a="b\\] c"] msg, an escaped backslash followed by a bare], which RFC 5424 does not allow in a PARAM-VALUE. The regexp parser does not end the structured data at that], and with this change neither does the string parser. On master, the string parser returns extradata[x@1 a="b]and messagec"] msg.The new test
test_parse_with_rfc5424_structured_data_includes_escaped_right_bracketcovers both engines. It runs the input from the issue, the same input without MSG, the input with a second SD-ELEMENT, and the two inputs above. For the string engine only, it also runs the input from the review with an invalid byte in MSG,m\xFFsg. The regexp engine raisesArgumentErrorfor that input, on master too. On master, 5 string rows fail and the other 6 rows pass. With this change, all 11 pass. For the string rows, the expected extradata has the backslashes removed, as described above.Locally with Ruby 3.4.12 on macOS,
test/plugin/test_parser_syslog.rbandtest/plugin/test_in_syslog.rbpass.Docs Changes:
N/A
Release Note:
parser_syslog: do not end RFC5424 structured data at an escaped
]withparser_engine stringAssisted-by: Claude Opus 5.5 (Claude Code)