[main]>worker0 ERROR Unable to copy file /var/log/logstash/logstash-plain-2018-01-23.log to /var/log/logstash/logstash-plain-2018-01-23.log

[pedrorochagoncalves]

Hi,

This is my first post here, so please excuse any mistakes on my end.

We have a couple of servers running logstash 5.6.3-1 and we've recently found this article here:

Logging | Elasticsearch Guide [master] | Elastic

We configured our log4j2.properties to something similar:

status = error
name = LogstashPropertiesConfig

appender.rolling.type = RollingFile
appender.rolling.name = plain_rolling
appender.rolling.fileName = ${sys:ls.logs}/logstash-${sys:ls.log.format}.log
appender.rolling.filePattern = ${sys:ls.logs}/logstash-${sys:ls.log.format}-%d{yyyy-MM-dd}.log
appender.rolling.policies.type = Policies
appender.rolling.policies.time.type = TimeBasedTriggeringPolicy
appender.rolling.policies.time.interval = 1
appender.rolling.policies.time.modulate = true
appender.rolling.policies.size.type = SizeBasedTriggeringPolicy
appender.rolling.policies.size.size = 10MB
appender.rolling.layout.type = PatternLayout
appender.rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %-.10000m%n
appender.rolling.strategy.type = DefaultRolloverStrategy
appender.rolling.strategy.fileIndex = nomax
appender.rolling.strategy.action.type = Delete
appender.rolling.strategy.action.basepath = ${sys:ls.logs}
appender.rolling.strategy.action.condition.type = IfFileName
appender.rolling.strategy.action.condition.glob = logstash-${sys:ls.log.format}-*
appender.rolling.strategy.action.condition.nested_condition.type = IfAccumulatedFileSize
appender.rolling.strategy.action.condition.nested_condition.exceeds = 128MB

appender.json_rolling.type = RollingFile
appender.json_rolling.name = json_rolling
appender.json_rolling.fileName = ${sys:ls.logs}/logstash-${sys:ls.log.format}.log
appender.json_rolling.filePattern = ${sys:ls.logs}/logstash-${sys:ls.log.format}-%d{yyyy-MM-dd}.log
appender.json_rolling.policies.type = Policies
appender.json_rolling.policies.time.type = TimeBasedTriggeringPolicy
appender.json_rolling.policies.time.interval = 1
appender.json_rolling.policies.time.modulate = true
appender.json_rolling.layout.type = JSONLayout
appender.json_rolling.layout.compact = true
appender.json_rolling.layout.eventEol = true

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

Logstash starts fine with this config, so we left it running for a few days. When I checked /var/log/logstash I found that it was deleting all of the logfiles that were older than the current day. Current content of that directory is:

ls -lh /var/log/logstash
total 16M
-rw-r--r-- 1 root adm 11M Jan 23 16:41 logstash-plain-2018-01-23.log
-rw-r--r-- 1 root adm 5.3M Jan 23 16:43 logstash-plain.log
date
Tue Jan 23 16:44:14 UTC 2018

This is weird because we configured log4j2 to delete when the accumulated log file size reached 128MB. We then checked the upstart logs for logstash and found the following:

2018-01-23 16:26:36,584 [main]>worker1 ERROR Unable to move file /var/log/logstash/logstash-plain-2018-01-23.log to /var/log/logstash/logstash-plain-2018-01-23.log: java.nio.file.NoSuchFileException /var/log/logstash/logstash-plain-2018-01-23.log -> /var/log/logstash/logstash-plain-2018-01-23.log
2018-01-23 16:26:36,584 [main]>worker1 ERROR Unable to copy file /var/log/logstash/logstash-plain-2018-01-23.log to /var/log/logstash/logstash-plain-2018-01-23.log: java.nio.file.NoSuchFileException /var/log/logstash/logstash-plain-2018-01-23.log
2018-01-23 16:31:55,529 [main]>worker0 ERROR Unable to move file /var/log/logstash/logstash-plain-2018-01-23.log to /var/log/logstash/logstash-plain-2018-01-23.log: java.nio.file.NoSuchFileException /var/log/logstash/logstash-plain-2018-01-23.log -> /var/log/logstash/logstash-plain-2018-01-23.log
2018-01-23 16:31:55,529 [main]>worker0 ERROR Unable to copy file /var/log/logstash/logstash-plain-2018-01-23.log to /var/log/logstash/logstash-plain-2018-01-23.log: java.nio.file.NoSuchFileException /var/log/logstash/logstash-plain-2018-01-23.log

It keeps printing these on and on. However, I don't understand what's wrong on our end. The process is currently running as root as we need it to access certain directories that belong to root. And the file that it's trying to copy exists. Is there a misconfiguration on our end or is this a bug?

I think this issue is the same as: <udp.0 ERROR Unable to copy file /var/log/logstash/logstash-plain-2017-10-11.log
But it was closed without a solution.

Any help is appreciated.

Cheers

[pedrorochagoncalves]

So I tried adding an increment to the Rollover File pattern:

appender.rolling.filePattern = ${sys:ls.logs}/logstash-${sys:ls.log.format}-%d{yyyy-MM-dd}-%i.log

And this is being ignored by log4j2. Surely I'm doing something wrong, but my question is what?

[pedrorochagoncalves]

Apparently log stash was using the other appender, the json_rolling one, which I was ignoring completely. I added the increment there and it started incrementing as expected.

Excuse the newbie here. Let's see if this works now and doesn't throw those errors.

[pedrorochagoncalves]

Yep, this now works as expected.

This is safe to close now.

Cheers!