Large Memory Consumption when ignore_same_log_interval

[yangjiel]

Describe the bug

My colleague Lester Lu and I found the issue related to #3401

The abnormal increasing memory usage is because of the ignore repeated log feature.
The current implementation uses dictionary to store the message as key. However, depends on the plugin implementation, the message could be the actual log that being send out. For example in azure-loganalytics, the log message is like log.fatal "Exception occured in posting to DataCollector API: " + "'#{ex}', data=>" + Yajl.dump(records). The records/log could be large like 1k bytes per log and never repeat.

It leads to the dictionary cached_log keep growing and the memory will never be released, therefore can observe significant memory usage for some plugins.

fluentd/lib/fluent/log.rb

Line 480 in 0a6d706

cached_log[message] = time

To Reproduce

Use plugin azure-loganalytics, config with an invalid account so that the log will not be send out, with large traffic 3k log/s, with ignore_same_log_interval 60s, observed memory usage keep increasing.

Expected behavior

Memory should not increase infinitely. The cached_log need to be freed once a while.

Your Environment

- Fluentd version: 1.15.2
- TD Agent version: 4.4.1
- Operating system: Ubuntu
- Kernel version:

Your Configuration

<system>
  log_level      info
  ignore_repeated_log_interval   60s
  ignore_same_log_interval       60s
</system>

<match **>
    @type azure-loganalytics
    customer_id invalidid
    shared_key anykeyshouldbefine
    log_type ApacheAccessLog
<buffer tag>
	@type                      memory
	chunk_limit_size           10M
	total_limit_size           50M
	flush_at_shutdown          true
	overflow_action            block
	retry_forever              true
	disable_chunk_backup       true
</buffer>
</match>

Your Error Log

No error, abnormal memory usage.

Additional context

No response

[ashie]

Thanks for your report!
Yep, we need to purge old logs.

fluentd/lib/fluent/log.rb

Lines 464 to 483 in 0a6d706

	def ignore_same_log?(time, message)
	cached_log = Thread.current[:last_same_log]
	if cached_log.nil?
	Thread.current[:last_same_log] = {message => time}
	return false
	end
	prev_time = cached_log[message]
	if prev_time
	if (time - prev_time) <= @ignore_same_log_interval
	true
	else
	cached_log[message] = time
	false
	end
	else
	cached_log[message] = time
	false
	end
	end

[daipom]

Wow, indeed.

[yangjiel]

May also relate to #1657

[daipom]

I have created PR to fix this!

• logger: Fix cache for ignore_same_log_interval growing unlimitedly #4229

Is it correct that this occurs only when using ignore_same_log_interval?

[yangjiel]

Yes correct. Thanks!

[daipom]

I modified the title a bit!
Thanks for your valuable report @yangjiel !