Bug 921232

Adding SLF4J (which will then just use log4j in hadoop) support and removing system.out.println in upcoming branch BZ92123.

Pull request for this is here, with log4j bindings added as default. 

WITHOUT bindings, confirmed that SLF4j is running properly (no logging occurs).

SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.

WITH log4j-slf4j bindings, the below can be seen in tests: 

13/04/01 14:54:41 INFO glusterfs.GlusterFileSystem: Initializing GlusterFS
13/04/01 14:54:41 INFO glusterfs.GlusterFileSystem: mount -t glusterfs jvyas.csb:/HadoopVol /tmp/gluster-test-mount-point/mount
13/04/01 14:54:41 INFO glusterfs.GlusterFileSystem: mount -t glusterfs jvyas.csb:/HadoopVol /tmp/gluster-test-mount-point/mount

https://github.com/gluster/hadoop-glusterfs/pull/23/files

REGARDING DEPENDENCIES:

The dependencies added here are not new and are indeed expected in hadoop, see https://raw.github.com/apurtell/hadoop/master/hadoop-common-project/hadoop-common/pom.xml, so at runtime, the slf4j-log4j12 and slf4j dependencies will already both be on the classpath in standard running hadoop installs.

Re dependency - slf4j 1.5.8 is packaged

Dependency fixed.

Also, regarding console appends (i.e. System.out syle logging that is easily viewed on the console):

#EXAMPLE OF A LOG4J FILE WITH CONSOLE APPENDER (i.e. logs that stream to the console instead of a file) 
log4j.rootLogger=DEBUG, CA

#Console Appender
log4j.appender.CA=org.apache.log4j.ConsoleAppender
log4j.appender.CA.layout=org.apache.log4j.PatternLayout
log4j.appender.CA.layout.ConversionPattern=%-4r [%t] %-5p %c %x - %m%n

Testing:
I installed and configured machines from Beaker by this manual https://wiki.test.redhat.com/HadoopGluster/Distros/HDP. When I ran command /usr/lib/hadoop/bin/hadoop fs -ls without any configuration changes, it printed:
14/02/13 10:07:15 INFO glusterfs.GlusterVolume: Initializing gluster volume..
14/02/13 10:07:15 INFO glusterfs.GlusterFileSystem: Configuring GlusterFS
14/02/13 10:07:15 INFO glusterfs.GlusterFileSystem: Initializing GlusterFS,  CRC disabled.
14/02/13 10:07:15 INFO glusterfs.GlusterFileSystem: GIT INFO={git.commit.id.abbrev=7b04317, git.commit.user.email=jayunit100, git.commit.message.full=Merge pull request #80 from jayunit100/2.1.6_release_fix_sudoers

include the sudoers file in the srpm, git.commit.id=7b04317ff5c13af8de192626fb40c4a0a5c37000, git.commit.message.short=Merge pull request #80 from jayunit100/2.1.6_release_fix_sudoers, git.commit.user.name=jay vyas, git.build.user.name=Unknown, git.commit.id.describe=2.1.6, git.build.user.email=Unknown, git.branch=master, git.commit.time=07.02.2014 @ 12:06:31 EST, git.build.time=07.02.2014 @ 13:58:44 EST}
14/02/13 10:07:15 INFO glusterfs.GlusterFileSystem: GIT_TAG=2.1.6
14/02/13 10:07:15 INFO glusterfs.GlusterFileSystem: Configuring GlusterFS
14/02/13 10:07:15 INFO glusterfs.GlusterVolume: Initializing gluster volume..
14/02/13 10:07:15 INFO glusterfs.GlusterVolume: Root of Gluster file system is /mnt/glusterfs
14/02/13 10:07:15 INFO glusterfs.GlusterVolume: mapreduce/superuser daemon : yarn
14/02/13 10:07:15 INFO glusterfs.GlusterVolume: Working directory is : glusterfs:/user/user1
14/02/13 10:07:15 INFO glusterfs.GlusterVolume: Write buffer size : 131072
Found 2 items
drwxr-x---   - user1 hadoop         65 2014-02-13 08:41 in
drwxrwx---   - user1 hadoop         12 2014-02-13 08:49 zblo

I tried to prove that log4j is really used and working by making some changes to its configuration file. I assumed that configuration file is located in /etc/hadoop/conf.empty/task-log4j.properties. I ran command:
 sed -i '/Pattern=/s/=/=QE/'  /etc/hadoop/conf.empty/log4j.properties

to check if output will be affected. "QE" was printed before every line starting with date and time (from log4j) as expected. Now I tried to run: 
sed -i 's/INFO/FATAL/'  /etc/hadoop/conf.empty/log4j.properties

I expected that setting log4j level to FATAL will result in not printing these lines with INFO level, but this command did not affect output at all.

I substitued FATAL-> TRACE with:
sed -i 's/FATAL/TRACE/'  /etc/hadoop/conf.empty/log4j.properties

it resulted to printing some more information on level DEBUG:
QE14/02/13 10:22:19 DEBUG lib.MutableMetricsFactory: field org.apache.hadoop.metrics2.lib.MutableRate org.apache.hadoop.security.UserGroupInformation$UgiMetrics.loginSuccess with annotation @org.apache.hadoop.metrics2.annotation.Metric(valueName=Time, about=, value=[Rate of successful kerberos logins and latency (milliseconds)], always=false, type=DEFAULT, sampleName=Ops)
QE14/02/13 10:22:19 DEBUG lib.MutableMetricsFactory: field org.apache.hadoop.metrics2.lib.MutableRate org.apache.hadoop.security.UserGroupInformation$UgiMetrics.loginFailure with annotation @org.apache.hadoop.metrics2.annotation.Metric(valueName=Time, about=, value=[Rate of failed kerberos logins and latency (milliseconds)], always=false, type=DEFAULT, sampleName=Ops)
QE14/02/13 10:22:19 DEBUG impl.MetricsSystemImpl: UgiMetrics, User and group related metrics

I think this behaviour is strange, because output verbosity can be enhanced by setting output level to TRACE but not reduced by setting FATAL. Is this behaviour correct (maybe some hack?) or there are another configuration files or fact that I am missing? Please provide me any info that could be relevant to this.

I did changes to configuration file as root and I ran "/usr/lib/hadoop/bin/hadoop fs -ls" commands as another user. Tested with rhs-hadoop-2.1.6-2.

We arent coupled to Log4J, necessarily SLF4J is the official logging API We use - so dependeing on your classpath (you can see it in System.getProperties), your log configuratino will vary.

So, basically you will have to 

(1) check that the log4j-slf4j bindings are in your classpath. 
(2) Determine how to configure logging for that particular binding.

I asked my question because I did not understand log4j configuration file clearly and did changes of verbosity wrong. Verbosity can be changed by setting line log4j.threshold=XXX. Thank you for hint.

Tested with versions:

Hortonworks Hadoop distribution:
Ambari: ambari-server-1.4.4.23-1.noarch
Stack : HDP-2.0.6.GlusterFS
hadoop-2.2.0.2.0.6.0-101.el6.x86_64

Red Hat Storage Server 3.0:
glusterfs-3.6.0.18-1.el6rhs.x86_64

RHS Hadoop plugin:
rhs-hadoop-2.3.2-5.el6rhs.noarch
rhs-hadoop-install-1_27-1.el6rhs.noarch


command: hadoop fs -ls /

output:

14/07/23 14:19:40 DEBUG lib.MutableMetricsFactory: field org.apache.hadoop.metrics2.lib.MutableRate org.apache.hadoop.security.UserGroupInformation$UgiMetrics.loginSuccess with annotation @org.apache.hadoop.metrics2.annotation.Metric(valueName=Time, about=, value=[Rate of successful kerberos logins and latency (milliseconds)], always=false, type=DEFAULT, sampleName=Ops)
14/07/23 14:19:40 DEBUG lib.MutableMetricsFactory: field org.apache.hadoop.metrics2.lib.MutableRate org.apache.hadoop.security.UserGroupInformation$UgiMetrics.loginFailure with annotation @org.apache.hadoop.metrics2.annotation.Metric(valueName=Time, about=, value=[Rate of failed kerberos logins and latency (milliseconds)], always=false, type=DEFAULT, sampleName=Ops)
14/07/23 14:19:40 DEBUG impl.MetricsSystemImpl: UgiMetrics, User and group related metrics
14/07/23 14:19:40 INFO glusterfs.GlusterVolume: Initializing gluster volume..
14/07/23 14:19:40 INFO glusterfs.GlusterFileSystem: Configuring GlusterFS
14/07/23 14:19:40 INFO glusterfs.GlusterFileSystem: Initializing GlusterFS,  CRC disabled.
14/07/23 14:19:40 INFO glusterfs.GlusterFileSystem: GIT INFO={git.commit.id.abbrev=bace8a2, git.commit.user.email=bchilds.rdu2.redhat.com, git.commit.message.full=[update RPM spec file/changelog] - 2.3.2
, git.commit.id=bace8a2d0269353c9ad293c8b2509ae145b56888, git.commit.message.short=[update RPM spec file/changelog] - 2.3.2, git.commit.user.name=Brad Childs, git.build.user.name=Unknown, git.commit.id.describe=2.3.10-9-gbace8a2, git.build.user.email=Unknown, git.branch=2.3.2, git.commit.time=10.07.2014 @ 09:59:23 EDT, git.build.time=10.07.2014 @ 10:10:47 EDT}
14/07/23 14:19:40 INFO glusterfs.GlusterFileSystem: GIT_TAG=2.3.10
14/07/23 14:19:40 INFO glusterfs.GlusterFileSystem: Configuring GlusterFS
14/07/23 14:19:40 INFO glusterfs.GlusterVolume: Initializing gluster volume..
14/07/23 14:19:40 ERROR glusterfs.GlusterVolume: Could not find property: fs.glusterfs.fuse.
.
.
.

From the output can be seen that Log4j is obviously working. Logging can be configured by modifying /etc/hadoop/conf.empty/log4j.properties. Problem mentioned in description of BZ is gone -> VERIFIED.

This bug is getting closed because a release has been made available that should address the reported issue. In case the problem is still not fixed with glusterfs-3.7.0, please open a new bug report.

glusterfs-3.7.0 has been announced on the Gluster mailinglists [1], packages for several distributions should become available in the near future. Keep an eye on the Gluster Users mailinglist [2] and the update infrastructure for your distribution.

[1] http://thread.gmane.org/gmane.comp.file-systems.gluster.devel/10939
[2] http://thread.gmane.org/gmane.comp.file-systems.gluster.user