You are viewing a plain text version of this content. The canonical link for it is here.
Posted to common-issues@hadoop.apache.org by "Jackie Chang (JIRA)" <ji...@apache.org> on 2013/09/28 02:59:02 UTC

[jira] [Updated] (HADOOP-2687) 1707 added errant INFO-level logging to DFSClient

     [ https://issues.apache.org/jira/browse/HADOOP-2687?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Jackie Chang updated HADOOP-2687:
---------------------------------

    Description: 
Marking this a blocker because it looks bad and it looks unintentional.  If it this turns out to not be a blocker for Hadoop, it will become one for HBase because 2/3rds of our DEBUG-level logs are filled with these DFSClient messages.  Below is a sample:

{code}
...
2008-01-23 01:17:31,506 DEBUG org.apache.hadoop.hbase.HStore: compaction for HStore 1028785192/info needed.
2008-01-23 01:17:31,506 DEBUG org.apache.hadoop.hbase.HRegion: 1028785192/info needs compaction
2008-01-23 01:17:31,506 INFO org.apache.hadoop.hbase.HRegion: starting compaction on region .META.,,1
2008-01-23 01:17:31,506 DEBUG org.apache.hadoop.hbase.HStore: started compaction of 4 files using hdfs://aa0-000-12.u.powerset.com:9123/hbase123/.META./compaction.dir for 1028785192/info
2008-01-23 01:17:31,548 INFO org.apache.hadoop.fs.DFSClient: Allocating new block
2008-01-23 01:17:31,549 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX.0:50010
2008-01-23 01:17:31,549 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..142:50010
2008-01-23 01:17:31,549 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..139:50010
2008-01-23 01:17:31,549 INFO org.apache.hadoop.fs.DFSClient: Connecting to XX.XX.XX..140:50010
2008-01-23 01:17:31,635 INFO org.apache.hadoop.fs.DFSClient: Closing old block blk_-1043800255529565106
2008-01-23 01:17:31,660 INFO org.apache.hadoop.fs.DFSClient: Allocating new block
2008-01-23 01:17:31,661 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..140:50010
2008-01-23 01:17:31,661 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..139:50010
2008-01-23 01:17:31,661 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..141:50010
2008-01-23 01:17:31,661 INFO org.apache.hadoop.fs.DFSClient: Connecting to XX.XX.XX..140:50010
2008-01-23 01:17:31,748 INFO org.apache.hadoop.fs.DFSClient: Closing old block blk_-8906552400781425824
2008-01-23 01:17:31,793 INFO org.apache.hadoop.fs.DFSClient: Allocating new block
2008-01-23 01:17:31,794 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..140:50010
2008-01-23 01:17:31,794 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..139:50010
2008-01-23 01:17:31,794 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..141:50010
2008-01-23 01:17:31,794 INFO org.apache.hadoop.fs.DFSClient: Connecting to XX.XX.XX..140:50010
2008-01-23 01:17:31,881 INFO org.apache.hadoop.fs.DFSClient: Closing old block blk_3933085663541821686
2008-01-23 01:17:31,902 DEBUG org.apache.hadoop.hbase.HStore: moving 1028785192/info/1089676733326611803 in hdfs:/XX.XX.XX.:9123/hbase123/.META./compaction.dir to 1028785192/info/8081034940986786580 in hdfs://XX.XX.XX.:9123/hbase123/.META. for 1028785192/info
2008-01-23 01:17:31,992 INFO org.apache.hadoop.hbase.HRegion: compaction completed on region .META.,,1. Took 0sec
...
{code}

This issue was originally reported over in hadoop-user by Billy Preston.

  was:
Marking this a blocker because it looks bad and it looks unintentional.  If it this turns out to not be a blocker for hadoop, it will become one for hbase because 2/3rds of our DEBUG-level logs are filled with these DFSClient messages.  Below is a sample:

{code}
...
2008-01-23 01:17:31,506 DEBUG org.apache.hadoop.hbase.HStore: compaction for HStore 1028785192/info needed.
2008-01-23 01:17:31,506 DEBUG org.apache.hadoop.hbase.HRegion: 1028785192/info needs compaction
2008-01-23 01:17:31,506 INFO org.apache.hadoop.hbase.HRegion: starting compaction on region .META.,,1
2008-01-23 01:17:31,506 DEBUG org.apache.hadoop.hbase.HStore: started compaction of 4 files using hdfs://aa0-000-12.u.powerset.com:9123/hbase123/.META./compaction.dir for 1028785192/info
2008-01-23 01:17:31,548 INFO org.apache.hadoop.fs.DFSClient: Allocating new block
2008-01-23 01:17:31,549 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX.0:50010
2008-01-23 01:17:31,549 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..142:50010
2008-01-23 01:17:31,549 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..139:50010
2008-01-23 01:17:31,549 INFO org.apache.hadoop.fs.DFSClient: Connecting to XX.XX.XX..140:50010
2008-01-23 01:17:31,635 INFO org.apache.hadoop.fs.DFSClient: Closing old block blk_-1043800255529565106
2008-01-23 01:17:31,660 INFO org.apache.hadoop.fs.DFSClient: Allocating new block
2008-01-23 01:17:31,661 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..140:50010
2008-01-23 01:17:31,661 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..139:50010
2008-01-23 01:17:31,661 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..141:50010
2008-01-23 01:17:31,661 INFO org.apache.hadoop.fs.DFSClient: Connecting to XX.XX.XX..140:50010
2008-01-23 01:17:31,748 INFO org.apache.hadoop.fs.DFSClient: Closing old block blk_-8906552400781425824
2008-01-23 01:17:31,793 INFO org.apache.hadoop.fs.DFSClient: Allocating new block
2008-01-23 01:17:31,794 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..140:50010
2008-01-23 01:17:31,794 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..139:50010
2008-01-23 01:17:31,794 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..141:50010
2008-01-23 01:17:31,794 INFO org.apache.hadoop.fs.DFSClient: Connecting to XX.XX.XX..140:50010
2008-01-23 01:17:31,881 INFO org.apache.hadoop.fs.DFSClient: Closing old block blk_3933085663541821686
2008-01-23 01:17:31,902 DEBUG org.apache.hadoop.hbase.HStore: moving 1028785192/info/1089676733326611803 in hdfs:/XX.XX.XX.:9123/hbase123/.META./compaction.dir to 1028785192/info/8081034940986786580 in hdfs://XX.XX.XX.:9123/hbase123/.META. for 1028785192/info
2008-01-23 01:17:31,992 INFO org.apache.hadoop.hbase.HRegion: compaction completed on region .META.,,1. Took 0sec
...
{code}

This issue was originally reported over in hadoop-user by Billy Preston.

    
> 1707 added errant INFO-level logging to DFSClient
> -------------------------------------------------
>
>                 Key: HADOOP-2687
>                 URL: https://issues.apache.org/jira/browse/HADOOP-2687
>             Project: Hadoop Common
>          Issue Type: Bug
>            Reporter: stack
>            Assignee: stack
>            Priority: Blocker
>             Fix For: 0.16.0
>
>         Attachments: dfsclient.patch
>
>
> Marking this a blocker because it looks bad and it looks unintentional.  If it this turns out to not be a blocker for Hadoop, it will become one for HBase because 2/3rds of our DEBUG-level logs are filled with these DFSClient messages.  Below is a sample:
> {code}
> ...
> 2008-01-23 01:17:31,506 DEBUG org.apache.hadoop.hbase.HStore: compaction for HStore 1028785192/info needed.
> 2008-01-23 01:17:31,506 DEBUG org.apache.hadoop.hbase.HRegion: 1028785192/info needs compaction
> 2008-01-23 01:17:31,506 INFO org.apache.hadoop.hbase.HRegion: starting compaction on region .META.,,1
> 2008-01-23 01:17:31,506 DEBUG org.apache.hadoop.hbase.HStore: started compaction of 4 files using hdfs://aa0-000-12.u.powerset.com:9123/hbase123/.META./compaction.dir for 1028785192/info
> 2008-01-23 01:17:31,548 INFO org.apache.hadoop.fs.DFSClient: Allocating new block
> 2008-01-23 01:17:31,549 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX.0:50010
> 2008-01-23 01:17:31,549 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..142:50010
> 2008-01-23 01:17:31,549 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..139:50010
> 2008-01-23 01:17:31,549 INFO org.apache.hadoop.fs.DFSClient: Connecting to XX.XX.XX..140:50010
> 2008-01-23 01:17:31,635 INFO org.apache.hadoop.fs.DFSClient: Closing old block blk_-1043800255529565106
> 2008-01-23 01:17:31,660 INFO org.apache.hadoop.fs.DFSClient: Allocating new block
> 2008-01-23 01:17:31,661 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..140:50010
> 2008-01-23 01:17:31,661 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..139:50010
> 2008-01-23 01:17:31,661 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..141:50010
> 2008-01-23 01:17:31,661 INFO org.apache.hadoop.fs.DFSClient: Connecting to XX.XX.XX..140:50010
> 2008-01-23 01:17:31,748 INFO org.apache.hadoop.fs.DFSClient: Closing old block blk_-8906552400781425824
> 2008-01-23 01:17:31,793 INFO org.apache.hadoop.fs.DFSClient: Allocating new block
> 2008-01-23 01:17:31,794 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..140:50010
> 2008-01-23 01:17:31,794 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..139:50010
> 2008-01-23 01:17:31,794 INFO org.apache.hadoop.fs.DFSClient: pipeline = XX.XX.XX..141:50010
> 2008-01-23 01:17:31,794 INFO org.apache.hadoop.fs.DFSClient: Connecting to XX.XX.XX..140:50010
> 2008-01-23 01:17:31,881 INFO org.apache.hadoop.fs.DFSClient: Closing old block blk_3933085663541821686
> 2008-01-23 01:17:31,902 DEBUG org.apache.hadoop.hbase.HStore: moving 1028785192/info/1089676733326611803 in hdfs:/XX.XX.XX.:9123/hbase123/.META./compaction.dir to 1028785192/info/8081034940986786580 in hdfs://XX.XX.XX.:9123/hbase123/.META. for 1028785192/info
> 2008-01-23 01:17:31,992 INFO org.apache.hadoop.hbase.HRegion: compaction completed on region .META.,,1. Took 0sec
> ...
> {code}
> This issue was originally reported over in hadoop-user by Billy Preston.

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira