Help! Multiple tasks wirite one log occurs log covered.

Hi all:

Now we have a proplem in our system, we have multiple task per datasource, and have 125 datasources, now we found that if we rolling up log every day(just like 11-06-12:00, the log will rolling up), there are multiple task, whichmeans multiple progresses to write log, and I can’t lock the log in conf in log4j, for example:

we have 2 task which means 2 progresses to write log, now the time is 2016-11-07-00:00, before this time the 2 tasks are all write log named middmanager.log

Task A:

a) observed the rolling time, rename middmanager.log to middmanager-2016-11-06.log

b) generate new log named middmanager.log.

Task B:

a) observed the rolling time, find that middmanager-2016-11-06.log exists, delete the middmanager-2016-11-06.log(so we lost all the log in 2016-11-06), rename middmanager.log to middmanager-2016-11-06.log. generate new log named middmanager.log.

b) now because Task A has the new middmanager-2016-11-06.log’s file handle, so it will write to middmanager-2016-11-06.log util this task finish, so we found that the history log only has one task’s life cycle time.

Can some help us? if we can solve this problem through change conf?

if this is the issue in druid, we can change the source code and propose a pull request.

Thanks all, hope your reply.

Hey Haoxiang,

I’m not sure if I’m understanding your situation correctly, so let me know if I’m mistaken here:

My understanding is that all of your logs from your middle manager and tasks are getting written to the same file because of your log4j configuration, but all these processes writing to the same file is causing issues, is that correct? I’m also assuming you’re not intending to have all the tasks writing to middmanager.log and only want the middle manager process writing to that file. This makes sense because the indexing service manages logging for tasks through setting the druid.indexer.logs.type property.

Probably what’s happening is your peon processes are picking up your log4j config file on the classpath and applying it unexpectedly. You can take a look at this link for how log4j discovers configuration for the logger: https://logging.apache.org/log4j/2.x/manual/configuration.html

For example if you called your custom og4j config log4j2.xml and put it on your classpath, it’ll get picked up by all the peon processes as well. To avoid this, you can call it something else and then set log4j.configurationFile in the middle manager runtime.properties and it’ll be applied to the middle manager only (and make sure that druid.indexer.runner.allowedPrefixes doesn’t whitelist ‘log4j’).

hi David:

actually, we want all task logs, not only middmanager log, and we set all the tasks write to the same log, let’s call it A.log, it will be ok all the day, but util to the end of the day, because we set the log4j rolling file, so the A.log will backup to A-2016-11-07.log, so we find multiple tasks rolling up the log will conflict, occurs the following situation:

Task A:

a) observed the rolling time, rename A.log to A-2016-11-06.log

b) generate new log named A.log.

Task B:

a) observed the rolling time, find that A-2016-11-06.log exists, delete the A-2016-11-06.log(so we lost all the log in 2016-11-06), rename A.log to A-2016-11-06.log. generate new log named A.log.

b) now because Task A has the new A-2016-11-06.log’s file handle, so it will write to A-2016-11-06.log util this task finish, so we found that the history log only has one task’s life cycle time.

like the situation from this webpage(http://blog.csdn.net/lskyne/article/details/38443995),(it’s written by Chinese).

log4j RollingFileAppender can not add lock to the file so it will cause this situation.

we only find middmanager log occurs this situation we assume because only middmanager have multiple progresses write one log.

So how can we solve this problem? now we just use logrotate to split log ourselves.

在 2016年11月8日星期二 UTC+8下午2:52:46,David Lim写道:

Ah okay I understand. As far as I can tell from reading docs, what you’re trying to do isn’t supported by the rolling file appender. A suggested solution is to use the SocketAppender with a SocketServer and configure the SocketServer to use rolling files. This page might be a good rough starting point: http://howtodoinjava.com/log4j/log4j-socketappender-and-socket-server-example/

Others with more familiarity with log4j2 might be able to offer other suggestions.

yeah this can work it but if we have lots of logs, I think this will be a bottleneck in network. So we just use logrotate to split logs in local, in my mind if task logs can named by its taskname will make it work, so maybe this will be a optimization that rename the logs and merge when rolling up.

在 2016年11月9日星期三 UTC+8上午3:10:42,David Lim写道:

You could also consider running a SocketServer on each middle manager to aggregate the logs from the MM / peons on that server, that way the data won’t have to traverse the network.