Return-Path: X-Original-To: apmail-incubator-flume-user-archive@minotaur.apache.org Delivered-To: apmail-incubator-flume-user-archive@minotaur.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 0B6867E33 for ; Tue, 4 Oct 2011 17:26:54 +0000 (UTC) Received: (qmail 75560 invoked by uid 500); 4 Oct 2011 17:26:54 -0000 Delivered-To: apmail-incubator-flume-user-archive@incubator.apache.org Received: (qmail 75400 invoked by uid 500); 4 Oct 2011 17:26:53 -0000 Mailing-List: contact flume-user-help@incubator.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: flume-user@incubator.apache.org Delivered-To: mailing list flume-user@incubator.apache.org Received: (qmail 75386 invoked by uid 99); 4 Oct 2011 17:26:52 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 04 Oct 2011 17:26:52 +0000 X-ASF-Spam-Status: No, hits=1.5 required=5.0 tests=FREEMAIL_FROM,HTML_MESSAGE,RCVD_IN_DNSWL_LOW,SPF_PASS,WEIRD_PORT X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of cgandevia@gmail.com designates 209.85.214.47 as permitted sender) Received: from [209.85.214.47] (HELO mail-bw0-f47.google.com) (209.85.214.47) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 04 Oct 2011 17:26:48 +0000 Received: by bke11 with SMTP id 11so948094bke.6 for ; Tue, 04 Oct 2011 10:26:26 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=mime-version:from:date:message-id:subject:to:content-type; bh=cJnIOZ2XU2rUfWgMZhVkF9UWJrFZlKA6PzXyetnvWGQ=; b=NmGODmxsiVc0ybfMULmc64D9Dc0/wWkxffK/RNI2hGzU9K4FY9MDt92yeX6dbs6Sde rEi2P6kr+cBkJn5nkX/TGRSLQ7c92ZXiYi86aLEfh6c9EOkeLHIvqHUDqkf9/bgDB6It 3VyT7L4LiGtg0+XnAC9iN0vEgcMXEcvlZyxfw= Received: by 10.204.138.130 with SMTP id a2mr887969bku.367.1317749186152; Tue, 04 Oct 2011 10:26:26 -0700 (PDT) MIME-Version: 1.0 Received: by 10.204.42.75 with HTTP; Tue, 4 Oct 2011 10:25:46 -0700 (PDT) From: Cameron Gandevia Date: Tue, 4 Oct 2011 10:25:46 -0700 Message-ID: Subject: DirectDriver Error To: flume-user@incubator.apache.org, flume-dev Content-Type: multipart/alternative; boundary=0015174c152224c7a704ae7c646c --0015174c152224c7a704ae7c646c Content-Type: text/plain; charset=UTF-8 Hey I am noticing the following exception in my collector logs. Whenever it happens my collector goes down and does not reconnect. I am using trunk build as of Oct 3. I have a feeling it some kind a race condition with the number of file handles open. Has anyone else experienced this problem? 2011-10-04 14:31:43,386 [logicalNode collector0_log_dir-3497] INFO com.cloudera.flume.core.connector.DirectDriver - Connector logicalNode collector0_log_dir-3497 exited with error: Blocked append interrupted by rotation event java.lang.InterruptedException: Blocked append interrupted by rotation event at com.cloudera.flume.handlers.rolling.RollSink.append(RollSink.java:209) at com.cloudera.flume.core.EventSinkDecorator.append(EventSinkDecorator.java:60) at com.cloudera.flume.core.MaskDecorator.append(MaskDecorator.java:43) at com.cloudera.flume.core.EventSinkDecorator.append(EventSinkDecorator.java:60) at com.cloudera.flume.handlers.debug.InsistentOpenDecorator.append(InsistentOpenDecorator.java:169) at com.cloudera.flume.core.EventSinkDecorator.append(EventSinkDecorator.java:60) at com.cloudera.flume.handlers.debug.StubbornAppendSink.append(StubbornAppendSink.java:71) at com.cloudera.flume.core.EventSinkDecorator.append(EventSinkDecorator.java:60) at com.cloudera.flume.handlers.debug.InsistentAppendDecorator.append(InsistentAppendDecorator.java:110) at com.cloudera.flume.core.EventSinkDecorator.append(EventSinkDecorator.java:60) at com.cloudera.flume.handlers.endtoend.AckChecksumChecker.append(AckChecksumChecker.java:113) at com.cloudera.flume.core.EventSinkDecorator.append(EventSinkDecorator.java:60) at com.cloudera.flume.handlers.batch.UnbatchingDecorator.append(UnbatchingDecorator.java:62) at com.cloudera.flume.core.EventSinkDecorator.append(EventSinkDecorator.java:60) at com.cloudera.flume.handlers.batch.GunzipDecorator.append(GunzipDecorator.java:81) at com.cloudera.flume.collector.CollectorSink.append(CollectorSink.java:222) at com.cloudera.flume.core.EventSinkDecorator.append(EventSinkDecorator.java:60) at com.cloudera.flume.core.extractors.DateExtractor.append(DateExtractor.java:86) at com.cloudera.flume.core.EventSinkDecorator.append(EventSinkDecorator.java:60) at com.cloudera.flume.core.extractors.RegexExtractor.append(RegexExtractor.java:88) at com.cloudera.flume.core.connector.DirectDriver$PumperThread.run(DirectDriver.java:133) 2011-10-04 14:31:43,387 [logicalNode collector0_log_dir-3497] INFO com.cloudera.flume.collector.CollectorSource - closed 2011-10-04 14:31:44,393 [logicalNode collector0_log_dir-3497] INFO com.cloudera.flume.handlers.thrift.ThriftEventSource - Closed server on port 36892... 2011-10-04 14:31:44,393 [logicalNode collector0_log_dir-3497] INFO com.cloudera.flume.handlers.thrift.ThriftEventSource - Queue still has 1000 elements ... 2011-10-04 14:31:54,402 [logicalNode collector0_log_dir-3497] WARN com.cloudera.flume.handlers.thrift.ThriftEventSource - Close timed out due to no progress. Closing despite having 1000 values still enqueued 2011-10-04 14:31:54,402 [logicalNode collector0_log_dir-3497] INFO com.cloudera.flume.handlers.rolling.RollSink - closing RollSink 'escapedCustomDfs("hdfs:// van-mang-perf-hadoop-namenode1.globalrelay.net:8020/rawLogs/%{dateyear}-%{datemonth}-%{dateday}/%{datehr}00/%{host}","raw-%{rolltag}" )' 2011-10-04 14:31:54,402 [logicalNode collector0_log_dir-3497] INFO com.cloudera.flume.handlers.rolling.RollSink - double close 'escapedCustomDfs("hdfs:// van-mang-perf-hadoop-namenode1.globalrelay.net:8020/rawLogs/%{dateyear}-%{datemonth}-%{dateday}/%{datehr}00/%{host}","raw-%{rolltag}" )' 2011-10-04 14:31:54,402 [logicalNode collector0_log_dir-3497] ERROR com.cloudera.flume.core.connector.DirectDriver - Exiting driver logicalNode collector0_log_dir-3497 in error state CollectorSource | RegexExtractor because Blocked append interrupted by rotation event --0015174c152224c7a704ae7c646c Content-Type: text/html; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Hey

I am noticing the following exception in my collecto= r logs. Whenever it happens my collector goes down and does not reconnect. = I am using trunk build as of Oct 3. I have a feeling it some kind a race co= ndition with the number of file handles open. Has anyone else experienced t= his problem?

2011-10-04 14:31:43,386 [logicalNode collector0_lo= g_dir-3497] INFO =C2=A0com.cloudera.flume.core.connector.DirectDriver - Con= nector logicalNode collector0_log_dir-3497 exited with error: Blocked appen= d interrupted by rotation event
java.lang.InterruptedException: Blocked append interrupted by rotation= event
=C2=A0 =C2=A0 =C2=A0 =C2=A0 at com.cloudera.flume.handlers= .rolling.RollSink.append(RollSink.java:209)
=C2=A0 =C2=A0 =C2=A0 = =C2=A0 at com.cloudera.flume.core.EventSinkDecorator.append(EventSinkDecora= tor.java:60)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 at com.cloudera.flume.core.MaskDecorator.a= ppend(MaskDecorator.java:43)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 at com.c= loudera.flume.core.EventSinkDecorator.append(EventSinkDecorator.java:60)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 at com.cloudera.flume.handlers.debug.In= sistentOpenDecorator.append(InsistentOpenDecorator.java:169)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 at com.cloudera.flume.core.EventSinkDecora= tor.append(EventSinkDecorator.java:60)
=C2=A0 =C2=A0 =C2=A0 =C2= =A0 at com.cloudera.flume.handlers.debug.StubbornAppendSink.append(Stubborn= AppendSink.java:71)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 at com.cloudera.f= lume.core.EventSinkDecorator.append(EventSinkDecorator.java:60)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 at com.cloudera.flume.handlers.debug.Insis= tentAppendDecorator.append(InsistentAppendDecorator.java:110)
=C2= =A0 =C2=A0 =C2=A0 =C2=A0 at com.cloudera.flume.core.EventSinkDecorator.appe= nd(EventSinkDecorator.java:60)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 at com.cloudera.flume.handlers.endtoend.Ac= kChecksumChecker.append(AckChecksumChecker.java:113)
=C2=A0 =C2= =A0 =C2=A0 =C2=A0 at com.cloudera.flume.core.EventSinkDecorator.append(Even= tSinkDecorator.java:60)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 at com.cloude= ra.flume.handlers.batch.UnbatchingDecorator.append(UnbatchingDecorator.java= :62)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 at com.cloudera.flume.core.EventSinkDecora= tor.append(EventSinkDecorator.java:60)
=C2=A0 =C2=A0 =C2=A0 =C2= =A0 at com.cloudera.flume.handlers.batch.GunzipDecorator.append(GunzipDecor= ator.java:81)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 at com.cloudera.flume.c= ollector.CollectorSink.append(CollectorSink.java:222)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 at com.cloudera.flume.core.EventSinkDecora= tor.append(EventSinkDecorator.java:60)
=C2=A0 =C2=A0 =C2=A0 =C2= =A0 at com.cloudera.flume.core.extractors.DateExtractor.append(DateExtracto= r.java:86)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 at com.cloudera.flume.core= .EventSinkDecorator.append(EventSinkDecorator.java:60)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 at com.cloudera.flume.core.extractors.Rege= xExtractor.append(RegexExtractor.java:88)
=C2=A0 =C2=A0 =C2=A0 = =C2=A0 at com.cloudera.flume.core.connector.DirectDriver$PumperThread.run(D= irectDriver.java:133)
2011-10-04 14:31:43,387 [logicalNode collec= tor0_log_dir-3497] INFO =C2=A0com.cloudera.flume.collector.CollectorSource = - closed
2011-10-04 14:31:44,393 [logicalNode collector0_log_dir-3497] INFO =C2= =A0com.cloudera.flume.handlers.thrift.ThriftEventSource - Closed server on = port 36892...
2011-10-04 14:31:44,393 [logicalNode collector0_log= _dir-3497] INFO =C2=A0com.cloudera.flume.handlers.thrift.ThriftEventSource = - Queue still has 1000 elements ...
2011-10-04 14:31:54,402 [logicalNode collector0_log_dir-3497] WARN =C2= =A0com.cloudera.flume.handlers.thrift.ThriftEventSource - Close timed out d= ue to no progress. =C2=A0Closing despite having 1000 values still enqueued<= /div>
2011-10-04 14:31:54,402 [logicalNode collector0_log_dir-3497] INFO =C2=A0co= m.cloudera.flume.handlers.rolling.RollSink - closing RollSink 'escapedC= ustomDfs("hdfs://van-mang-perf-hadoop-namenode1.globalrelay.net:8020/rawLogs/%{dateye= ar}-%{datemonth}-%{dateday}/%{datehr}00/%{host}","raw-%{rollt= ag}" )'
2011-10-04 14:31:54,402 [logicalNode collector0_log_dir-3497] INFO =C2= =A0com.cloudera.flume.handlers.rolling.RollSink - double close 'escaped= CustomDfs("hdfs://van-mang-perf-hadoop-namenode1.globalrelay.net:8020/rawLogs/%{datey= ear}-%{datemonth}-%{dateday}/%{datehr}00/%{host}","raw-%{roll= tag}" )'
2011-10-04 14:31:54,402 [logicalNode collector0_log_dir-3497] ERROR co= m.cloudera.flume.core.connector.DirectDriver - Exiting driver logicalNode c= ollector0_log_dir-3497 in error state CollectorSource | RegexExtractor beca= use Blocked append interrupted by rotation event

--0015174c152224c7a704ae7c646c--