Return-Path: X-Original-To: apmail-zookeeper-bookkeeper-user-archive@minotaur.apache.org Delivered-To: apmail-zookeeper-bookkeeper-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 D026FC4EA for ; Thu, 10 May 2012 12:16:22 +0000 (UTC) Received: (qmail 64456 invoked by uid 500); 10 May 2012 12:16:22 -0000 Delivered-To: apmail-zookeeper-bookkeeper-user-archive@zookeeper.apache.org Received: (qmail 64334 invoked by uid 500); 10 May 2012 12:16:19 -0000 Mailing-List: contact bookkeeper-user-help@zookeeper.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: bookkeeper-user@zookeeper.apache.org Delivered-To: mailing list bookkeeper-user@zookeeper.apache.org Received: (qmail 64301 invoked by uid 99); 10 May 2012 12:16:18 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 10 May 2012 12:16:18 +0000 X-ASF-Spam-Status: No, hits=-0.1 required=5.0 tests=HTML_MESSAGE,RCVD_IN_DNSWL_MED,SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of jnagro@hubspot.com designates 74.125.149.151 as permitted sender) Received: from [74.125.149.151] (HELO na3sys009aog124.obsmtp.com) (74.125.149.151) by apache.org (qpsmtpd/0.29) with SMTP; Thu, 10 May 2012 12:16:12 +0000 Received: from mail-ob0-f170.google.com ([209.85.214.170]) (using TLSv1) by na3sys009aob124.postini.com ([74.125.148.12]) with SMTP ID DSNKT6uxdwbWOCf9joMU5MwlIqf0kcOvIKA8@postini.com; Thu, 10 May 2012 05:15:52 PDT Received: by mail-ob0-f170.google.com with SMTP id uo13so3764493obb.1 for ; Thu, 10 May 2012 05:15:51 -0700 (PDT) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=20120113; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :cc:content-type:x-gm-message-state; bh=iyr78gTJgWjgQfTvcSX19ZCBiC9LHFb2c7Iz6UKIGgE=; b=QPCRoHoj2zFV7JNnuuBuMsf6v49uApLsFH24NSifoZ+E+hr390CScdQykkNGOfJdSo hhYQm8Eb+7rcbHLliHD7P1gNDht0XPHLHpxg9qqqlUp0A1QlQGfzPxUEwxJZlWSBm/wl RwZvNsNLRvsBnOdCgdkdW1D0UDTrqobX+rTW/XY+5h6HdKIwq1XHp+THxXmzg/Iznvz5 6JejQwuBqzwjQYFjhXpk2KC2DfjqYhgFhE75cFOryYUkNGlff2oHhDVkgS+aZg0aM6XK mUpMKaOKM77oYPdQEJLZAnI4ZVAXdNskS96L0wKsyTUY1FjCD2PSvN5Lb7uo6UmNkS6z YEHg== MIME-Version: 1.0 Received: by 10.182.115.74 with SMTP id jm10mr5285217obb.71.1336652151154; Thu, 10 May 2012 05:15:51 -0700 (PDT) Received: by 10.182.11.99 with HTTP; Thu, 10 May 2012 05:15:51 -0700 (PDT) In-Reply-To: References: Date: Thu, 10 May 2012 08:15:51 -0400 Message-ID: Subject: Re: update to most recent snapshot results in weird logs From: John Nagro To: Sijie Guo Cc: bookkeeper-user@zookeeper.apache.org Content-Type: multipart/alternative; boundary=f46d0444ea83a8680404bfad9423 X-Gm-Message-State: ALoCoQmyxgKQ5vNXK5H/lDRvgR3IWeQIaC0xSjoPMew6fLmuPJ7C/e5VXFmQAJOcPbxmp7NsYM8r X-Virus-Checked: Checked by ClamAV on apache.org --f46d0444ea83a8680404bfad9423 Content-Type: text/plain; charset=ISO-8859-1 Thanks Sijie! On Thu, May 10, 2012 at 1:47 AM, Sijie Guo wrote: > Hello John, > > ah, these noise message are due to the messy scan mechanism we used in > garbage collector thread running in bookie server. > Currently each garbage collection run, it would scan entry log files > starting from zero, it would try to scan those garbage collected entry log > files again, which cause printing such message. > > I created BOOKKEEPER-251 to fix it today. > > Thanks, > Sijie > > On Thu, May 10, 2012 at 4:04 AM, John Nagro wrote: > >> Hello - >> >> I was seeing error messages related to BOOKKEEPER-229. I saw that the >> patch was incorporated in, so I upgraded one of my QA bk servers, which >> resulted in these sorts of error messages over and over in the logs: >> >> >> 2012-05-09 15:58:52,742 - INFO >> [GarbageCollectorThread:GarbageCollectorThread@466] - Extracting entry >> log meta from entryLogId: 0 >> 2012-05-09 15:58:52,743 - WARN [GarbageCollectorThread:EntryLogger@386] >> - Failed to get channel to scan entry log: 0.log >> 2012-05-09 15:58:52,743 - WARN >> [GarbageCollectorThread:GarbageCollectorThread@473] - Premature >> exception when processing 0recovery will take care of the problem >> java.io.FileNotFoundException: No file for log 0 >> at >> org.apache.bookkeeper.bookie.EntryLogger.findFile(EntryLogger.java:366) >> at >> org.apache.bookkeeper.bookie.EntryLogger.getChannelForLogId(EntryLogger.java:340) >> at >> org.apache.bookkeeper.bookie.EntryLogger.scanEntryLog(EntryLogger.java:384) >> at >> org.apache.bookkeeper.bookie.GarbageCollectorThread.extractMetaFromEntryLog(GarbageCollectorThread.java:485) >> at >> org.apache.bookkeeper.bookie.GarbageCollectorThread.extractMetaFromEntryLogs(GarbageCollectorThread.java:470) >> at >> org.apache.bookkeeper.bookie.GarbageCollectorThread.run(GarbageCollectorThread.java:189) >> 2012-05-09 15:58:52,743 - INFO >> [GarbageCollectorThread:GarbageCollectorThread@466] - Extracting entry >> log meta from entryLogId: 1 >> 2012-05-09 15:58:52,743 - WARN [GarbageCollectorThread:EntryLogger@386] >> - Failed to get channel to scan entry log: 1.log >> 2012-05-09 15:58:52,744 - WARN >> [GarbageCollectorThread:GarbageCollectorThread@473] - Premature >> exception when processing 1recovery will take care of the problem >> java.io.FileNotFoundException: No file for log 1 >> at >> org.apache.bookkeeper.bookie.EntryLogger.findFile(EntryLogger.java:366) >> at >> org.apache.bookkeeper.bookie.EntryLogger.getChannelForLogId(EntryLogger.java:340) >> at >> org.apache.bookkeeper.bookie.EntryLogger.scanEntryLog(EntryLogger.java:384) >> at >> org.apache.bookkeeper.bookie.GarbageCollectorThread.extractMetaFromEntryLog(GarbageCollectorThread.java:485) >> at >> org.apache.bookkeeper.bookie.GarbageCollectorThread.extractMetaFromEntryLogs(GarbageCollectorThread.java:470) >> at >> org.apache.bookkeeper.bookie.GarbageCollectorThread.run(GarbageCollectorThread.java:189) >> 2012-05-09 15:58:52,744 - INFO >> [GarbageCollectorThread:GarbageCollectorThread@466] - Extracting entry >> log meta from entryLogId: 2 >> 2012-05-09 15:58:52,744 - WARN [GarbageCollectorThread:EntryLogger@386] >> - Failed to get channel to scan entry log: 2.log >> 2012-05-09 15:58:52,744 - WARN >> [GarbageCollectorThread:GarbageCollectorThread@473] - Premature >> exception when processing 2recovery will take care of the problem >> java.io.FileNotFoundException: No file for log 2 >> at >> org.apache.bookkeeper.bookie.EntryLogger.findFile(EntryLogger.java:366) >> at >> org.apache.bookkeeper.bookie.EntryLogger.getChannelForLogId(EntryLogger.java:340) >> at >> org.apache.bookkeeper.bookie.EntryLogger.scanEntryLog(EntryLogger.java:384) >> at >> org.apache.bookkeeper.bookie.GarbageCollectorThread.extractMetaFromEntryLog(GarbageCollectorThread.java:485) >> at >> org.apache.bookkeeper.bookie.GarbageCollectorThread.extractMetaFromEntryLogs(GarbageCollectorThread.java:470) >> at >> org.apache.bookkeeper.bookie.GarbageCollectorThread.run(GarbageCollectorThread.java:189) >> 2012-05-09 15:58:52,744 - INFO >> [GarbageCollectorThread:GarbageCollectorThread@466] - Extracting entry >> log meta from entryLogId: 4 >> 2012-05-09 15:58:52,744 - WARN [GarbageCollectorThread:EntryLogger@386] >> - Failed to get channel to scan entry log: 4.log >> 2012-05-09 15:58:52,745 - WARN >> [GarbageCollectorThread:GarbageCollectorThread@473] - Premature >> exception when processing 4recovery will take care of the problem >> java.io.FileNotFoundException: No file for log 4 >> at >> org.apache.bookkeeper.bookie.EntryLogger.findFile(EntryLogger.java:366) >> at >> org.apache.bookkeeper.bookie.EntryLogger.getChannelForLogId(EntryLogger.java:340) >> at >> org.apache.bookkeeper.bookie.EntryLogger.scanEntryLog(EntryLogger.java:384) >> at >> org.apache.bookkeeper.bookie.GarbageCollectorThread.extractMetaFromEntryLog(GarbageCollectorThread.java:485) >> at >> org.apache.bookkeeper.bookie.GarbageCollectorThread.extractMetaFromEntryLogs(GarbageCollectorThread.java:470) >> at >> org.apache.bookkeeper.bookie.GarbageCollectorThread.run(GarbageCollectorThread.java:189) >> >> >> Any ideas? >> >> Thanks! >> >> -John Nagro >> > > --f46d0444ea83a8680404bfad9423 Content-Type: text/html; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable Thanks=A0Sijie!

On Thu= , May 10, 2012 at 1:47 AM, Sijie Guo <guosijie@gmail.com> w= rote:
Hello John,=A0

ah, these = noise message are due to the messy scan mechanism we used in garbage collec= tor thread running in bookie server.=A0
Currently each garbage collection run, it would scan entry log files s= tarting from zero, it would try to scan those garbage collected entry log f= iles again, which cause printing such message.

I created BOOKKEEPER-251 to fix it today.
Thanks,
Sijie

On Thu, May 10, 2012 at 4:04 AM, Joh= n Nagro <jnagro@hubspot.com> wrote:
Hello -

I was seeing error messages = related to=A0BOOKKEEPER-229. I saw that the patch was incorporated in, so I= upgraded one of my QA bk servers, which resulted in these sorts of error m= essages over and over in the logs:

=A0
2012-05-09 15:58:52,742 - INFO =A0[G= arbageCollectorThread:GarbageCollectorThread@466] - Extracting entry log me= ta from entryLogId: 0
2012-05-09 15:58:52,743 - WARN =A0[GarbageC= ollectorThread:EntryLogger@386] - Failed to get channel to scan entry log: = 0.log
2012-05-09 15:58:52,743 - WARN =A0[GarbageCollectorThread:GarbageColle= ctorThread@473] - Premature exception when processing 0recovery will take c= are of the problem
java.io.FileNotFoundException: No file for log= 0
=A0 =A0 =A0 =A0 at org.apache.bookkeeper.bookie.EntryLogger.findFile(E= ntryLogger.java:366)
=A0 =A0 =A0 =A0 at org.apache.bookkeeper.boo= kie.EntryLogger.getChannelForLogId(EntryLogger.java:340)
=A0 =A0 = =A0 =A0 at org.apache.bookkeeper.bookie.EntryLogger.scanEntryLog(EntryLogge= r.java:384)
=A0 =A0 =A0 =A0 at org.apache.bookkeeper.bookie.GarbageCollectorThread= .extractMetaFromEntryLog(GarbageCollectorThread.java:485)
=A0 =A0= =A0 =A0 at org.apache.bookkeeper.bookie.GarbageCollectorThread.extractMeta= FromEntryLogs(GarbageCollectorThread.java:470)
=A0 =A0 =A0 =A0 at org.apache.bookkeeper.bookie.GarbageCollectorThread= .run(GarbageCollectorThread.java:189)
2012-05-09 15:58:52,743 - I= NFO =A0[GarbageCollectorThread:GarbageCollectorThread@466] - Extracting ent= ry log meta from entryLogId: 1
2012-05-09 15:58:52,743 - WARN =A0[GarbageCollectorThread:EntryLogger@= 386] - Failed to get channel to scan entry log: 1.log
2012-05-09 = 15:58:52,744 - WARN =A0[GarbageCollectorThread:GarbageCollectorThread@473] = - Premature exception when processing 1recovery will take care of the probl= em
java.io.FileNotFoundException: No file for log 1
=A0 =A0 =A0= =A0 at org.apache.bookkeeper.bookie.EntryLogger.findFile(EntryLogger.java:= 366)
=A0 =A0 =A0 =A0 at org.apache.bookkeeper.bookie.EntryLogger.= getChannelForLogId(EntryLogger.java:340)
=A0 =A0 =A0 =A0 at org.apache.bookkeeper.bookie.EntryLogger.scanEntryL= og(EntryLogger.java:384)
=A0 =A0 =A0 =A0 at org.apache.bookkeeper= .bookie.GarbageCollectorThread.extractMetaFromEntryLog(GarbageCollectorThre= ad.java:485)
=A0 =A0 =A0 =A0 at org.apache.bookkeeper.bookie.GarbageCollectorThread= .extractMetaFromEntryLogs(GarbageCollectorThread.java:470)
=A0 = =A0 =A0 =A0 at org.apache.bookkeeper.bookie.GarbageCollectorThread.run(Garb= ageCollectorThread.java:189)
2012-05-09 15:58:52,744 - INFO =A0[GarbageCollectorThread:GarbageColle= ctorThread@466] - Extracting entry log meta from entryLogId: 2
20= 12-05-09 15:58:52,744 - WARN =A0[GarbageCollectorThread:EntryLogger@386] - = Failed to get channel to scan entry log: 2.log
2012-05-09 15:58:52,744 - WARN =A0[GarbageCollectorThread:GarbageColle= ctorThread@473] - Premature exception when processing 2recovery will take c= are of the problem
java.io.FileNotFoundException: No file for log= 2
=A0 =A0 =A0 =A0 at org.apache.bookkeeper.bookie.EntryLogger.findFile(E= ntryLogger.java:366)
=A0 =A0 =A0 =A0 at org.apache.bookkeeper.boo= kie.EntryLogger.getChannelForLogId(EntryLogger.java:340)
=A0 =A0 = =A0 =A0 at org.apache.bookkeeper.bookie.EntryLogger.scanEntryLog(EntryLogge= r.java:384)
=A0 =A0 =A0 =A0 at org.apache.bookkeeper.bookie.GarbageCollectorThread= .extractMetaFromEntryLog(GarbageCollectorThread.java:485)
=A0 =A0= =A0 =A0 at org.apache.bookkeeper.bookie.GarbageCollectorThread.extractMeta= FromEntryLogs(GarbageCollectorThread.java:470)
=A0 =A0 =A0 =A0 at org.apache.bookkeeper.bookie.GarbageCollectorThread= .run(GarbageCollectorThread.java:189)
2012-05-09 15:58:52,744 - I= NFO =A0[GarbageCollectorThread:GarbageCollectorThread@466] - Extracting ent= ry log meta from entryLogId: 4
2012-05-09 15:58:52,744 - WARN =A0[GarbageCollectorThread:EntryLogger@= 386] - Failed to get channel to scan entry log: 4.log
2012-05-09 = 15:58:52,745 - WARN =A0[GarbageCollectorThread:GarbageCollectorThread@473] = - Premature exception when processing 4recovery will take care of the probl= em
java.io.FileNotFoundException: No file for log 4
=A0 =A0 =A0= =A0 at org.apache.bookkeeper.bookie.EntryLogger.findFile(EntryLogger.java:= 366)
=A0 =A0 =A0 =A0 at org.apache.bookkeeper.bookie.EntryLogger.= getChannelForLogId(EntryLogger.java:340)
=A0 =A0 =A0 =A0 at org.apache.bookkeeper.bookie.EntryLogger.scanEntryL= og(EntryLogger.java:384)
=A0 =A0 =A0 =A0 at org.apache.bookkeeper= .bookie.GarbageCollectorThread.extractMetaFromEntryLog(GarbageCollectorThre= ad.java:485)
=A0 =A0 =A0 =A0 at org.apache.bookkeeper.bookie.GarbageCollectorThread= .extractMetaFromEntryLogs(GarbageCollectorThread.java:470)
=A0 = =A0 =A0 =A0 at org.apache.bookkeeper.bookie.GarbageCollectorThread.run(Garb= ageCollectorThread.java:189)


Any ideas?

Thanks!

-John Nagr= o


--f46d0444ea83a8680404bfad9423--