Log4j2 Rolling File Strategy Only Rolls Once

[Kris_Felscher]

I'm having issues with the log4j2 rolling file appender. It only writes the first rollover file.

Here's my config:

status = error
name = LogstashPropertiesConfig

appender.console.type = Console
appender.console.name = plain_console
appender.console.layout.type = PatternLayout
appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c]%notEmpty{[%X{pipeline.id}]}%notEmpty{[%X{plugin.id}]} %m%n

appender.rolling.type = RollingFile
appender.rolling.name = plain_rolling
appender.rolling.fileName = ${sys:ls.logs}/logstash-current.log
appender.rolling.filePattern = ${sys:ls.logs}/{yyyy-MM-dd}-%i.log
appender.rolling.layout.type = PatternLayout
appender.rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c]%notEmpty{[%X{pipeline.id}]}%notEmpty{[%X{plugin.id}]} %m%n
appender.rolling.avoid_pipelined_filter.type = PipelineRoutingFilter
appender.rolling.policies.type = Policies
appender.rolling.policies.size.type = SizeBasedTriggeringPolicy
appender.rolling.policies.size.size = 10MB
appender.rolling.strategy.type = DefaultRolloverStrategy
appender.rolling.strategy.fileIndex = nomax

rootLogger.level = ${sys:ls.log.level}
rootLogger.appenderRef.console.ref = ${sys:ls.log.format}_console
rootLogger.appenderRef.rolling.ref = ${sys:ls.log.format}_rolling

I would expect this config to roll over every 10MB, creating the files:

• 2023-10-18-1.log
• 2023-10-18-2.log
• 2023-10-18-3.log
• ...etc
• logstash-current.log

where logstash-current.log is the log currently being written to, and the others being older data at 10MB each.

Instead, what I'm seeing is this:

• 2023-10-18-1.log
• logstash-current.log

The 2023-10-18-1.log file is indeed 10MB, but instead of creating 2023-10-18-2.log, log4j2 just deletes and reuses logstash-current.log (which never grows over 10MB).

Any thoughts?

[Badger]

This thread might (or might not be helpful). Read all the way to the end

[Kris_Felscher]

Thank you, but no, that's not helpful. My problem is that the rolling appender only rolls once then continues to overwrite the "current" log file instead of creating a second log file.

[Kris_Felscher]

Update:

So it turns out that it is actually rolling files over. It's just not doing it as expected.

Right now I have 4 files:

• 2023-10-31-1.log (created 14:27)
• 2023-10-31-2.log (created 14:35)
• 2023-10-31-3.log (created 14:47)
• logstash-current.log

The problem is that log4j2 seems to be schizophrenic on when it decides to create the next file.

• 2023-10-31-1.log contains data from 14:25 to 14:27
• 2023-10-31-2.log contains data from 14:35 to 14:38
• 2023-10-31-3.log contains data from 14:47 to 14:50

So there's an 8-10 minute gap between rollovers where the logstash-current.log file just keeps getting recycled.

This makes absolutely no sense...

[Kris_Felscher]

OK, I figured it out.

We're storing our logs on an Azure Storage File Share which is mounted to the filesystem. Apparently, Log4j2 fails silently when it's unable to roll a file. I haven't identified the exact reason that the filesystem failure is occurring, but this is a Kubernetes/Azure issue, not Log4j2.