[jira] [Commented] (FLUME-2385) Flume spans log file with "Spooling Directory Source runner has shutdown" messages at INFO level
[ https://issues.apache.org/jira/browse/FLUME-2385?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14206103#comment-14206103 ] Hudson commented on FLUME-2385: --- UNSTABLE: Integrated in flume-trunk #692 (See [https://builds.apache.org/job/flume-trunk/692/]) FLUME-2385. Remove incorrect log message at INFO level in Spool Directory Source. (hshreedharan: http://git-wip-us.apache.org/repos/asf/flume/repo?p=flume.git&a=commit&h=2c18533253be786b9c60bf687cdf38d2384d2625) * flume-ng-core/src/main/java/org/apache/flume/source/SpoolDirectorySource.java > Flume spans log file with "Spooling Directory Source runner has shutdown" > messages at INFO level > > > Key: FLUME-2385 > URL: https://issues.apache.org/jira/browse/FLUME-2385 > Project: Flume > Issue Type: Improvement >Affects Versions: v1.4.0 >Reporter: Justin Hayes >Assignee: Phil Scala >Priority: Minor > Fix For: v1.6.0 > > Attachments: FLUME-2385-0.patch > > > When I start an agent with the following config, the spooling directory > source emits "14/05/14 22:36:12 INFO source.SpoolDirectorySource: Spooling > Directory Source runner has shutdown." messages twice a second. Pretty > innocuous but it will fill up the file system needlessly and get in the way > of other INFO messages. > cis.sources = httpd > cis.sinks = loggerSink > cis.channels = mem2logger > cis.sources.httpd.type = spooldir > cis.sources.httpd.spoolDir = /var/log/httpd > cis.sources.httpd.trackerDir = /var/lib/flume-ng/tracker/httpd > cis.sources.httpd.channels = mem2logger > cis.sinks.loggerSink.type = logger > cis.sinks.loggerSink.channel = mem2logger > cis.channels.mem2logger.type = memory > cis.channels.mem2logger.capacity = 1 > cis.channels.mem2logger.transactionCapacity = 1000 -- This message was sent by Atlassian JIRA (v6.3.4#6332)
[jira] [Commented] (FLUME-2385) Flume spans log file with "Spooling Directory Source runner has shutdown" messages at INFO level
[ https://issues.apache.org/jira/browse/FLUME-2385?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14206087#comment-14206087 ] Hudson commented on FLUME-2385: --- UNSTABLE: Integrated in Flume-trunk-hbase-98 #49 (See [https://builds.apache.org/job/Flume-trunk-hbase-98/49/]) FLUME-2385. Remove incorrect log message at INFO level in Spool Directory Source. (hshreedharan: http://git-wip-us.apache.org/repos/asf/flume/repo?p=flume.git&a=commit&h=2c18533253be786b9c60bf687cdf38d2384d2625) * flume-ng-core/src/main/java/org/apache/flume/source/SpoolDirectorySource.java > Flume spans log file with "Spooling Directory Source runner has shutdown" > messages at INFO level > > > Key: FLUME-2385 > URL: https://issues.apache.org/jira/browse/FLUME-2385 > Project: Flume > Issue Type: Improvement >Affects Versions: v1.4.0 >Reporter: Justin Hayes >Assignee: Phil Scala >Priority: Minor > Fix For: v1.6.0 > > Attachments: FLUME-2385-0.patch > > > When I start an agent with the following config, the spooling directory > source emits "14/05/14 22:36:12 INFO source.SpoolDirectorySource: Spooling > Directory Source runner has shutdown." messages twice a second. Pretty > innocuous but it will fill up the file system needlessly and get in the way > of other INFO messages. > cis.sources = httpd > cis.sinks = loggerSink > cis.channels = mem2logger > cis.sources.httpd.type = spooldir > cis.sources.httpd.spoolDir = /var/log/httpd > cis.sources.httpd.trackerDir = /var/lib/flume-ng/tracker/httpd > cis.sources.httpd.channels = mem2logger > cis.sinks.loggerSink.type = logger > cis.sinks.loggerSink.channel = mem2logger > cis.channels.mem2logger.type = memory > cis.channels.mem2logger.capacity = 1 > cis.channels.mem2logger.transactionCapacity = 1000 -- This message was sent by Atlassian JIRA (v6.3.4#6332)
[jira] [Commented] (FLUME-2385) Flume spans log file with "Spooling Directory Source runner has shutdown" messages at INFO level
[ https://issues.apache.org/jira/browse/FLUME-2385?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14206030#comment-14206030 ] ASF subversion and git services commented on FLUME-2385: Commit 2c18533253be786b9c60bf687cdf38d2384d2625 in flume's branch refs/heads/trunk from [~hshreedharan] [ https://git-wip-us.apache.org/repos/asf?p=flume.git;h=2c18533 ] FLUME-2385. Remove incorrect log message at INFO level in Spool Directory Source. (Phil Scala via Hari Shreedharan) > Flume spans log file with "Spooling Directory Source runner has shutdown" > messages at INFO level > > > Key: FLUME-2385 > URL: https://issues.apache.org/jira/browse/FLUME-2385 > Project: Flume > Issue Type: Improvement >Affects Versions: v1.4.0 >Reporter: Justin Hayes >Assignee: Phil Scala >Priority: Minor > Fix For: v1.6.0 > > Attachments: FLUME-2385-0.patch > > > When I start an agent with the following config, the spooling directory > source emits "14/05/14 22:36:12 INFO source.SpoolDirectorySource: Spooling > Directory Source runner has shutdown." messages twice a second. Pretty > innocuous but it will fill up the file system needlessly and get in the way > of other INFO messages. > cis.sources = httpd > cis.sinks = loggerSink > cis.channels = mem2logger > cis.sources.httpd.type = spooldir > cis.sources.httpd.spoolDir = /var/log/httpd > cis.sources.httpd.trackerDir = /var/lib/flume-ng/tracker/httpd > cis.sources.httpd.channels = mem2logger > cis.sinks.loggerSink.type = logger > cis.sinks.loggerSink.channel = mem2logger > cis.channels.mem2logger.type = memory > cis.channels.mem2logger.capacity = 1 > cis.channels.mem2logger.transactionCapacity = 1000 -- This message was sent by Atlassian JIRA (v6.3.4#6332)
[jira] [Commented] (FLUME-2385) Flume spans log file with "Spooling Directory Source runner has shutdown" messages at INFO level
[ https://issues.apache.org/jira/browse/FLUME-2385?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14206031#comment-14206031 ] ASF subversion and git services commented on FLUME-2385: Commit c1512241c0104daa80f58c6146ecb759ef6417da in flume's branch refs/heads/flume-1.6 from [~hshreedharan] [ https://git-wip-us.apache.org/repos/asf?p=flume.git;h=c151224 ] FLUME-2385. Remove incorrect log message at INFO level in Spool Directory Source. (Phil Scala via Hari Shreedharan) > Flume spans log file with "Spooling Directory Source runner has shutdown" > messages at INFO level > > > Key: FLUME-2385 > URL: https://issues.apache.org/jira/browse/FLUME-2385 > Project: Flume > Issue Type: Improvement >Affects Versions: v1.4.0 >Reporter: Justin Hayes >Assignee: Phil Scala >Priority: Minor > Fix For: v1.6.0 > > Attachments: FLUME-2385-0.patch > > > When I start an agent with the following config, the spooling directory > source emits "14/05/14 22:36:12 INFO source.SpoolDirectorySource: Spooling > Directory Source runner has shutdown." messages twice a second. Pretty > innocuous but it will fill up the file system needlessly and get in the way > of other INFO messages. > cis.sources = httpd > cis.sinks = loggerSink > cis.channels = mem2logger > cis.sources.httpd.type = spooldir > cis.sources.httpd.spoolDir = /var/log/httpd > cis.sources.httpd.trackerDir = /var/lib/flume-ng/tracker/httpd > cis.sources.httpd.channels = mem2logger > cis.sinks.loggerSink.type = logger > cis.sinks.loggerSink.channel = mem2logger > cis.channels.mem2logger.type = memory > cis.channels.mem2logger.capacity = 1 > cis.channels.mem2logger.transactionCapacity = 1000 -- This message was sent by Atlassian JIRA (v6.3.4#6332)
[jira] [Commented] (FLUME-2385) Flume spans log file with "Spooling Directory Source runner has shutdown" messages at INFO level
[ https://issues.apache.org/jira/browse/FLUME-2385?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14205980#comment-14205980 ] Hari Shreedharan commented on FLUME-2385: - +1. Running tests and committing. > Flume spans log file with "Spooling Directory Source runner has shutdown" > messages at INFO level > > > Key: FLUME-2385 > URL: https://issues.apache.org/jira/browse/FLUME-2385 > Project: Flume > Issue Type: Improvement >Affects Versions: v1.4.0 >Reporter: Justin Hayes >Assignee: Phil Scala >Priority: Minor > Fix For: v1.6.0 > > Attachments: FLUME-2385-0.patch > > > When I start an agent with the following config, the spooling directory > source emits "14/05/14 22:36:12 INFO source.SpoolDirectorySource: Spooling > Directory Source runner has shutdown." messages twice a second. Pretty > innocuous but it will fill up the file system needlessly and get in the way > of other INFO messages. > cis.sources = httpd > cis.sinks = loggerSink > cis.channels = mem2logger > cis.sources.httpd.type = spooldir > cis.sources.httpd.spoolDir = /var/log/httpd > cis.sources.httpd.trackerDir = /var/lib/flume-ng/tracker/httpd > cis.sources.httpd.channels = mem2logger > cis.sinks.loggerSink.type = logger > cis.sinks.loggerSink.channel = mem2logger > cis.channels.mem2logger.type = memory > cis.channels.mem2logger.capacity = 1 > cis.channels.mem2logger.transactionCapacity = 1000 -- This message was sent by Atlassian JIRA (v6.3.4#6332)
[jira] [Commented] (FLUME-2385) Flume spans log file with "Spooling Directory Source runner has shutdown" messages at INFO level
[ https://issues.apache.org/jira/browse/FLUME-2385?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14205891#comment-14205891 ] Ye Xianjin commented on FLUME-2385: --- hi, [~scaph01], I think (according to my colleague) the more reasonable change is to set the log level to debug. > Flume spans log file with "Spooling Directory Source runner has shutdown" > messages at INFO level > > > Key: FLUME-2385 > URL: https://issues.apache.org/jira/browse/FLUME-2385 > Project: Flume > Issue Type: Improvement >Affects Versions: v1.4.0 >Reporter: Justin Hayes >Assignee: Phil Scala >Priority: Minor > Fix For: v1.6.0 > > Attachments: FLUME-2385-0.patch > > > When I start an agent with the following config, the spooling directory > source emits "14/05/14 22:36:12 INFO source.SpoolDirectorySource: Spooling > Directory Source runner has shutdown." messages twice a second. Pretty > innocuous but it will fill up the file system needlessly and get in the way > of other INFO messages. > cis.sources = httpd > cis.sinks = loggerSink > cis.channels = mem2logger > cis.sources.httpd.type = spooldir > cis.sources.httpd.spoolDir = /var/log/httpd > cis.sources.httpd.trackerDir = /var/lib/flume-ng/tracker/httpd > cis.sources.httpd.channels = mem2logger > cis.sinks.loggerSink.type = logger > cis.sinks.loggerSink.channel = mem2logger > cis.channels.mem2logger.type = memory > cis.channels.mem2logger.capacity = 1 > cis.channels.mem2logger.transactionCapacity = 1000 -- This message was sent by Atlassian JIRA (v6.3.4#6332)
[jira] [Commented] (FLUME-2385) Flume spans log file with "Spooling Directory Source runner has shutdown" messages at INFO level
[
https://issues.apache.org/jira/browse/FLUME-2385?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14033047#comment-14033047
]
Phil Scala commented on FLUME-2385:
---
Ed / Justin,
Looking at the code, there seems to be a code change that introduced this
behavior in the spool dir source,
Commit:
{noformat}
SHA-1: a345f611ba814c3689420edf4c2cc9b69ba3ac70
* FLUME-2283: Spool Dir source must check interrupt flag before writing to
channel
(Hari Shreedharan via Jarek Jarcec Cecho)
{noformat}
introduced this info logging statement and its logged all of the time,
irrespective if there is an error (you don't know how long I looked around for
an error today when I saw this being logged). The code in question is:
{code:java title=SpoolDirectorySource}
while (!Thread.interrupted()) {
List events = reader.readEvents(batchSize);
if (events.isEmpty()) {
break;
}
sourceCounter.addToEventReceivedCount(events.size());
sourceCounter.incrementAppendBatchReceivedCount();
try {
getChannelProcessor().processEventBatch(events);
reader.commit();
} catch (ChannelException ex) {
...
}
continue;
}
backoffInterval = 250;
sourceCounter.addToEventAcceptedCount(events.size());
sourceCounter.incrementAppendBatchAcceptedCount();
}
logger.info("Spooling Directory Source runner has shutdown.");
{code}
the issue is events.isEmpty() returns true when there is nothing new in the
spool dir, this calls the break and so the statement is logged. Since this is
called on a schedule, 500ms later the same thing happens over and over. I
believe the logging statement is not accurate because the source has not
shutdown, its just done checking for files for this iteration.
the fix to this issue is simply to remove this logging statement, which I will
submit a patch for.
> Flume spans log file with "Spooling Directory Source runner has shutdown"
> messages at INFO level
>
>
> Key: FLUME-2385
> URL: https://issues.apache.org/jira/browse/FLUME-2385
> Project: Flume
> Issue Type: Improvement
>Affects Versions: v1.4.0
>Reporter: Justin Hayes
>Priority: Minor
>
> When I start an agent with the following config, the spooling directory
> source emits "14/05/14 22:36:12 INFO source.SpoolDirectorySource: Spooling
> Directory Source runner has shutdown." messages twice a second. Pretty
> innocuous but it will fill up the file system needlessly and get in the way
> of other INFO messages.
> cis.sources = httpd
> cis.sinks = loggerSink
> cis.channels = mem2logger
> cis.sources.httpd.type = spooldir
> cis.sources.httpd.spoolDir = /var/log/httpd
> cis.sources.httpd.trackerDir = /var/lib/flume-ng/tracker/httpd
> cis.sources.httpd.channels = mem2logger
> cis.sinks.loggerSink.type = logger
> cis.sinks.loggerSink.channel = mem2logger
> cis.channels.mem2logger.type = memory
> cis.channels.mem2logger.capacity = 1
> cis.channels.mem2logger.transactionCapacity = 1000
--
This message was sent by Atlassian JIRA
(v6.2#6252)
[jira] [Commented] (FLUME-2385) Flume spans log file with "Spooling Directory Source runner has shutdown" messages at INFO level
[ https://issues.apache.org/jira/browse/FLUME-2385?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14003657#comment-14003657 ] Edward Sargisson commented on FLUME-2385: - I agree that this is highly annoying - especially so that you have to know to look back to just when the spamming started to determine what the failure actually was. However, I also think it's important that administrators know that the source has stopped. I would probably support simply logging a message saying, "Spooling Directory Source has stopped. Refer to the start of these messages to determine why." We could consider logging this only every 5s or similar but that's a bit more interesting to implement. > Flume spans log file with "Spooling Directory Source runner has shutdown" > messages at INFO level > > > Key: FLUME-2385 > URL: https://issues.apache.org/jira/browse/FLUME-2385 > Project: Flume > Issue Type: Improvement >Affects Versions: v1.4.0 >Reporter: Justin Hayes >Priority: Minor > > When I start an agent with the following config, the spooling directory > source emits "14/05/14 22:36:12 INFO source.SpoolDirectorySource: Spooling > Directory Source runner has shutdown." messages twice a second. Pretty > innocuous but it will fill up the file system needlessly and get in the way > of other INFO messages. > cis.sources = httpd > cis.sinks = loggerSink > cis.channels = mem2logger > cis.sources.httpd.type = spooldir > cis.sources.httpd.spoolDir = /var/log/httpd > cis.sources.httpd.trackerDir = /var/lib/flume-ng/tracker/httpd > cis.sources.httpd.channels = mem2logger > cis.sinks.loggerSink.type = logger > cis.sinks.loggerSink.channel = mem2logger > cis.channels.mem2logger.type = memory > cis.channels.mem2logger.capacity = 1 > cis.channels.mem2logger.transactionCapacity = 1000 -- This message was sent by Atlassian JIRA (v6.2#6252)
