[HADOOP-2687] 1707 added errant INFO-level logging to DFSClient

• Type: Bug
• Status: Closed
• Priority: Blocker
• Resolution: Fixed
• Fix Version/s: 0.16.0
• Assignee: Michael Stack
• Reporter: Michael Stack
• Created: 23/Jan/08 01:33
• Updated: 28/Sep/13 00:58
• Resolved: 24/Jan/08 19:00

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:

...
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
...

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