Bug 908526 - Hadoop benchmark TestDFSIO fails with “java.io.IOException: Stream closed.” glusterfs hadoop plugin attempts to close a closed stream.
Summary: Hadoop benchmark TestDFSIO fails with “java.io.IOException: Stream closed.” ...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: GlusterFS
Classification: Community
Component: gluster-hadoop
Version: mainline
Hardware: All
OS: Linux
urgent
high
Target Milestone: ---
Assignee: Jay Vyas
QA Contact: Martin Bukatovic
URL:
Whiteboard:
Depends On:
Blocks: 1057253
TreeView+ depends on / blocked
 
Reported: 2013-02-06 23:15 UTC by Diane Feddema
Modified: 2014-03-03 16:32 UTC (History)
7 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2014-03-03 16:32:38 UTC
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Embargoed:

Attachments (Terms of Use)

Description Diane Feddema 2013-02-06 23:15:35 UTC 
Description of problem:

Hadoop benchmark, TestDFSIO, fails when glusterfs hadoop plugin attempts to close a stream that is already closed. 

Version-Release number of selected component (if applicable):


How reproducible: very


Steps to Reproduce:
1. Install Intel hadoop distribution on RHS 2.0/RHEL 6.2
2. cd $HADOOP_INSTALL
3. bin/hadoop jar hadoop-test-1.0.3-Intel.jar TestDFSIO -write -nrFiles 10 -fileSize 1
  
Actual results:
java.io.IOException: Stream closed.
at org.apache.hadoop.fs.glusterfs.GlusterFUSEInputStream.close(GlusterFUSEInputStream.java:184)
        at java.io.FilterInputStream.close(FilterInputStream.java:172)
        at java.io.FilterInputStream.close(FilterInputStream.java:172)
        at sun.nio.cs.StreamDecoder.implClose(StreamDecoder.java:376)
        at sun.nio.cs.StreamDecoder.close(StreamDecoder.java:191)
        at java.io.InputStreamReader.close(InputStreamReader.java:199)
        at java.io.BufferedReader.close(BufferedReader.java:514)
        at org.apache.hadoop.fs.TestDFSIO.analyzeResult(TestDFSIO.java:358)
        at org.apache.hadoop.fs.TestDFSIO.run(TestDFSIO.java:462)
        at org.apache.hadoop.util.ToolRunner.run(ToolRunner.java:65)
        at org.apache.hadoop.util.ToolRunner.run(ToolRunner.java:79)
        at org.apache.hadoop.fs.TestDFSIO.main(TestDFSIO.java:317)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)


Expected results:
Note: these results were obtained using RHEL 6.2 + Intel Hadoop Distro 1.0.3 + HDFS 1.0.3 

[root@rhs-1 hadoop]# bin/hadoop jar hadoop-test-1.0.3-Intel.jar TestDFSIO -write -nrFiles 10 -fileSize 1
TestDFSIO.0.0.4
13/01/30 19:30:17 INFO fs.TestDFSIO: nrFiles = 10
13/01/30 19:30:17 INFO fs.TestDFSIO: fileSize (MB) = 1
13/01/30 19:30:17 INFO fs.TestDFSIO: bufferSize = 1000000
13/01/30 19:30:19 INFO fs.TestDFSIO: creating control file: 1 mega bytes, 10 files
13/01/30 19:30:49 INFO fs.TestDFSIO: created control files for: 10 files
13/01/30 19:30:50 INFO mapred.FileInputFormat: Total input paths to process : 10
13/01/30 19:30:51 INFO mapred.JobClient: Running job: job_201301301924_0001
13/01/30 19:30:52 INFO mapred.JobClient:  map 0% reduce 0%
13/01/30 19:31:17 INFO mapred.JobClient:  map 10% reduce 0%
13/01/30 19:31:18 INFO mapred.JobClient:  map 20% reduce 0%
13/01/30 19:31:25 INFO mapred.JobClient:  map 30% reduce 0%
13/01/30 19:31:26 INFO mapred.JobClient:  map 40% reduce 0%
13/01/30 19:31:35 INFO mapred.JobClient:  map 50% reduce 0%
13/01/30 19:31:36 INFO mapred.JobClient:  map 60% reduce 0%
13/01/30 19:31:42 INFO mapred.JobClient:  map 60% reduce 20%
13/01/30 19:32:10 INFO mapred.JobClient:  map 80% reduce 20%
13/01/30 19:32:11 INFO mapred.JobClient:  map 90% reduce 20%
13/01/30 19:32:12 INFO mapred.JobClient:  map 90% reduce 30%
13/01/30 19:32:16 INFO mapred.JobClient:  map 100% reduce 30%
13/01/30 19:32:22 INFO mapred.JobClient:  map 100% reduce 100%
13/01/30 19:32:27 INFO mapred.JobClient: Job complete: job_201301301924_0001
13/01/30 19:32:27 INFO mapred.JobClient: Counters: 30
13/01/30 19:32:27 INFO mapred.JobClient:   Job Counters
13/01/30 19:32:27 INFO mapred.JobClient:     Launched reduce tasks=1
13/01/30 19:32:27 INFO mapred.JobClient:     SLOTS_MILLIS_MAPS=208951
13/01/30 19:32:27 INFO mapred.JobClient:     Total time spent by all reduces waiting after reserving slots (ms)=0
13/01/30 19:32:27 INFO mapred.JobClient:     Total time spent by all maps waiting after reserving slots (ms)=0
13/01/30 19:32:27 INFO mapred.JobClient:     Launched map tasks=10
13/01/30 19:32:27 INFO mapred.JobClient:     Data-local map tasks=10
13/01/30 19:32:27 INFO mapred.JobClient:     SLOTS_MILLIS_REDUCES=63332
13/01/30 19:32:27 INFO mapred.JobClient:   File Input Format Counters
13/01/30 19:32:27 INFO mapred.JobClient:     Bytes Read=1120
13/01/30 19:32:27 INFO mapred.JobClient:   File Output Format Counters
13/01/30 19:32:27 INFO mapred.JobClient:     Bytes Written=75
13/01/30 19:32:27 INFO mapred.JobClient:   FileSystemCounters
13/01/30 19:32:27 INFO mapred.JobClient:     FILE_BYTES_READ=402
13/01/30 19:32:27 INFO mapred.JobClient:     HDFS_BYTES_READ=2320
13/01/30 19:32:27 INFO mapred.JobClient:     FILE_BYTES_WRITTEN=270574
13/01/30 19:32:27 INFO mapred.JobClient:     HDFS_BYTES_WRITTEN=10485835
13/01/30 19:32:27 INFO mapred.JobClient:   Map-Reduce Framework
13/01/30 19:32:27 INFO mapred.JobClient:     Map output materialized bytes=967
13/01/30 19:32:27 INFO mapred.JobClient:     Map input records=10
13/01/30 19:32:27 INFO mapred.JobClient:     Reduce shuffle bytes=967
13/01/30 19:32:27 INFO mapred.JobClient:     Spilled Records=100
13/01/30 19:32:27 INFO mapred.JobClient:     Map output bytes=721
13/01/30 19:32:27 INFO mapred.JobClient:     Total committed heap usage (bytes)=1969623040
13/01/30 19:32:27 INFO mapred.JobClient:     CPU time spent (ms)=13100
13/01/30 19:32:27 INFO mapred.JobClient:     Map input bytes=260
13/01/30 19:32:27 INFO mapred.JobClient:     SPLIT_RAW_BYTES=1200
13/01/30 19:32:27 INFO mapred.JobClient:     Combine input records=0
13/01/30 19:32:27 INFO mapred.JobClient:     Reduce input records=50
13/01/30 19:32:27 INFO mapred.JobClient:     Reduce input groups=5
13/01/30 19:32:27 INFO mapred.JobClient:     Combine output records=0
13/01/30 19:32:27 INFO mapred.JobClient:     Physical memory (bytes) snapshot=2117144576
13/01/30 19:32:27 INFO mapred.JobClient:     Reduce output records=5
13/01/30 19:32:27 INFO mapred.JobClient:     Virtual memory (bytes) snapshot=12456374272
13/01/30 19:32:27 INFO mapred.JobClient:     Map output records=50
13/01/30 19:32:27 INFO fs.TestDFSIO: ----- TestDFSIO ----- : write
13/01/30 19:32:27 INFO fs.TestDFSIO:            Date & time: Wed Jan 30 19:32:27 UTC 2013
13/01/30 19:32:27 INFO fs.TestDFSIO:        Number of files: 10
13/01/30 19:32:27 INFO fs.TestDFSIO: Total MBytes processed: 10
13/01/30 19:32:27 INFO fs.TestDFSIO:      Throughput mb/sec: 0.111393307490086
13/01/30 19:32:27 INFO fs.TestDFSIO: Average IO rate mb/sec: 0.5073503851890564
13/01/30 19:32:27 INFO fs.TestDFSIO:  IO rate std deviation: 0.4238647977968062
13/01/30 19:32:27 INFO fs.TestDFSIO:     Test exec time sec: 98.798
13/01/30 19:32:27 INFO fs.TestDFSIO:


Additional info: TestDFSIO passes with RHEL 6.2 + Intel Hadoop Distro + 1.0.3 HDFS 1.0.3
Comment 3 Scott Haines 2013-02-13 22:32:38 UTC 
Per Feb-13 bug triage meeting, reassigning to swatt.
Comment 4 Steve Watt 2013-02-18 20:29:09 UTC 
Assigning to Brad, who already has a patch.
Comment 5 Bradley Childs 2013-02-18 21:28:33 UTC 
The GlusterFUSEInputStream.close() method throwing exception if the stream had been closed previously.

Per the Java 1.6 closable() API, the exception shouldn't get raised if the stream was previously closed:

http://docs.oracle.com/javase/6/docs/api/java/io/Closeable.html

Fixed here:

https://github.com/gluster/hadoop-glusterfs/commit/b092116b798f130b94dc3b245c5b7add8b752f5a
Comment 6 Bradley Childs 2013-02-18 21:30:06 UTC 
reassign to jvyas for review/commit.
Comment 7 Jay Vyas 2013-02-19 05:07:31 UTC 
Looks like a solid fix.  

- its not tested At some point We will need mockito or another way to mock the inputstream class so that it can be created without actually talking to gluster.  in the interim, there is no test for this bug. 

- The passing build is here: http://build.gluster.org/job/GlusterFS-hadoop/64/

- Now Im proceeding to test this in my psuedo production cluster.

http://build.gluster.org/job/GlusterFS-hadoop/ws/target/glusterfs-0.20.2-0.1.jar
Comment 8 Jay Vyas 2013-02-19 18:00:50 UTC 
The below command line pasting demonstrates that 

(expected result) 1) With the new jar, brad's fix results in no exception thrown and that 
(negative control) 2) After removing the jar from the path, when the original glusterfs plugin is used, an exception is indeed thrown. 

Thus - this bug has been fixed ! Closing :).  To get the latest jar that contains this fix : 

"wget http://build.gluster.org/job/GlusterFS-hadoop/ws/target/glusterfs-0.20.2-0.1.jar"

and cp it to "/usr/lib/hadoop/lib/0Aaglusterfs-0.20.20-0.1.jar" on your vms. 

The result: Hadoop will load the 0aglusterf* jar classes first - and those will be on the classpath. 

The master branch has been taged as FIX_BZ908526 

[root@rhs-1 hadoop]#  bin/hadoop jar hadoop-test-1.0.3-Intel.jar TestDFSIO -write -nrFiles 10 -fileSize 1
TestDFSIO.0.0.4
13/02/19 17:37:51 INFO fs.TestDFSIO: nrFiles = 10
13/02/19 17:37:51 INFO fs.TestDFSIO: fileSize (MB) = 1
13/02/19 17:37:51 INFO fs.TestDFSIO: bufferSize = 1000000
13/02/19 17:37:51 WARN conf.Configuration: mapred-site.xml:a attempt to override final parameter: mapred.local.dir;  Ignoring.
13/02/19 17:37:52 WARN conf.Configuration: mapred-site.xml:a attempt to override final parameter: mapred.local.dir;  Ignoring.
Initializing GlusterFS
13/02/19 17:37:53 INFO fs.TestDFSIO: creating control file: 1 mega bytes, 10 files
13/02/19 17:37:56 INFO fs.TestDFSIO: created control files for: 10 files
13/02/19 17:37:56 WARN conf.Configuration: mapred-site.xml:a attempt to override final parameter: mapred.local.dir;  Ignoring.
13/02/19 17:37:56 WARN conf.Configuration: mapred-site.xml:a attempt to override final parameter: mapred.local.dir;  Ignoring.
13/02/19 17:37:57 INFO mapred.FileInputFormat: Total input paths to process : 10
13/02/19 17:37:59 INFO mapred.JobClient: Running job: job_201302191737_0001
13/02/19 17:38:00 INFO mapred.JobClient:  map 0% reduce 0%
13/02/19 17:38:16 INFO mapred.JobClient:  map 10% reduce 0%
13/02/19 17:38:17 INFO mapred.JobClient:  map 30% reduce 0%
13/02/19 17:38:21 INFO mapred.JobClient:  map 40% reduce 0%
13/02/19 17:38:22 INFO mapred.JobClient:  map 50% reduce 0%
13/02/19 17:38:24 INFO mapred.JobClient:  map 60% reduce 0%
13/02/19 17:38:26 INFO mapred.JobClient:  map 70% reduce 0%
13/02/19 17:38:28 INFO mapred.JobClient:  map 80% reduce 0%
13/02/19 17:38:29 INFO mapred.JobClient:  map 80% reduce 23%
13/02/19 17:38:31 INFO mapred.JobClient:  map 90% reduce 23%
13/02/19 17:38:34 INFO mapred.JobClient:  map 100% reduce 23%
13/02/19 17:38:38 INFO mapred.JobClient:  map 100% reduce 30%
13/02/19 17:38:41 INFO mapred.JobClient:  map 100% reduce 100%
13/02/19 17:38:46 INFO mapred.JobClient: Job complete: job_201302191737_0001
13/02/19 17:38:46 INFO mapred.JobClient: Counters: 29
13/02/19 17:38:46 INFO mapred.JobClient:   Job Counters 
13/02/19 17:38:46 INFO mapred.JobClient:     Launched reduce tasks=1
13/02/19 17:38:46 INFO mapred.JobClient:     SLOTS_MILLIS_MAPS=66161
13/02/19 17:38:46 INFO mapred.JobClient:     Total time spent by all reduces waiting after reserving slots (ms)=0
13/02/19 17:38:46 INFO mapred.JobClient:     Total time spent by all maps waiting after reserving slots (ms)=0
13/02/19 17:38:46 INFO mapred.JobClient:     Rack-local map tasks=4
13/02/19 17:38:46 INFO mapred.JobClient:     Launched map tasks=10
13/02/19 17:38:46 INFO mapred.JobClient:     Data-local map tasks=6
13/02/19 17:38:46 INFO mapred.JobClient:     SLOTS_MILLIS_REDUCES=24089
13/02/19 17:38:46 INFO mapred.JobClient:   File Input Format Counters 
13/02/19 17:38:46 INFO mapred.JobClient:     Bytes Read=0
13/02/19 17:38:46 INFO mapred.JobClient:   File Output Format Counters 
13/02/19 17:38:46 INFO mapred.JobClient:     Bytes Written=0
13/02/19 17:38:46 INFO mapred.JobClient:   FileSystemCounters
13/02/19 17:38:46 INFO mapred.JobClient:     FILE_BYTES_READ=381
13/02/19 17:38:46 INFO mapred.JobClient:     FILE_BYTES_WRITTEN=274389
13/02/19 17:38:46 INFO mapred.JobClient:   Map-Reduce Framework
13/02/19 17:38:46 INFO mapred.JobClient:     Map output materialized bytes=942
13/02/19 17:38:46 INFO mapred.JobClient:     Map input records=10
13/02/19 17:38:46 INFO mapred.JobClient:     Reduce shuffle bytes=942
13/02/19 17:38:46 INFO mapred.JobClient:     Spilled Records=100
13/02/19 17:38:46 INFO mapred.JobClient:     Map output bytes=700
13/02/19 17:38:46 INFO mapred.JobClient:     Total committed heap usage (bytes)=1931190272
13/02/19 17:38:46 INFO mapred.JobClient:     CPU time spent (ms)=3860
13/02/19 17:38:46 INFO mapred.JobClient:     Map input bytes=260
13/02/19 17:38:46 INFO mapred.JobClient:     SPLIT_RAW_BYTES=-4445
13/02/19 17:38:46 INFO mapred.JobClient:     Combine input records=0
13/02/19 17:38:46 INFO mapred.JobClient:     Reduce input records=50
13/02/19 17:38:46 INFO mapred.JobClient:     Reduce input groups=5
13/02/19 17:38:46 INFO mapred.JobClient:     Combine output records=0
13/02/19 17:38:46 INFO mapred.JobClient:     Physical memory (bytes) snapshot=2264080384
13/02/19 17:38:46 INFO mapred.JobClient:     Reduce output records=5
13/02/19 17:38:46 INFO mapred.JobClient:     Virtual memory (bytes) snapshot=13709123584
13/02/19 17:38:46 INFO mapred.JobClient:     Map output records=50
13/02/19 17:38:50 INFO fs.TestDFSIO: ----- TestDFSIO ----- : write
13/02/19 17:38:50 INFO fs.TestDFSIO:            Date & time: Tue Feb 19 17:38:46 UTC 2013
13/02/19 17:38:50 INFO fs.TestDFSIO:        Number of files: 10
13/02/19 17:38:50 INFO fs.TestDFSIO: Total MBytes processed: 10
13/02/19 17:38:50 INFO fs.TestDFSIO:      Throughput mb/sec: 44.44444444444444
13/02/19 17:38:50 INFO fs.TestDFSIO: Average IO rate mb/sec: 68.00105285644531
13/02/19 17:38:50 INFO fs.TestDFSIO:  IO rate std deviation: 35.83927301302903
13/02/19 17:38:50 INFO fs.TestDFSIO:     Test exec time sec: 50.878
13/02/19 17:38:50 INFO fs.TestDFSIO: 
[root@rhs-1 hadoop]# ls /v
var/          velocity.log  
[root@rhs-1 hadoop]# ls /var/lib/
alternatives/     dhclient/         glusterd/         iscsi/            nfs/              plymouth/         random-seed       selinux/          tpm/              yum/
authconfig/       dnsmasq/          hadoop/           libvirt/          nginx/            polkit-1/         rhsm/             sepolgen/         udev/             zookeeper/
dav/              games/            hive/             logrotate.status  ntp/              prelink/          rpm/              stateless/        up2date/          
dbus/             ganglia/          iptraf/           misc/             php/              puppet/           samba/            tftpboot/         vdsm/             
[root@rhs-1 hadoop]# ls /var/lib/h
hadoop/ hive/   
[root@rhs-1 hadoop]# ls /var/lib/h
hadoop/ hive/   
[root@rhs-1 hadoop]# ls /etc/
Display all 232 possibilities? (y or n)
[root@rhs-1 hadoop]# ls /etc/h
hadoop/      hal/         hbase/       hive/        host.conf    hosts        hosts.allow  hosts.deny   httpd/       
[root@rhs-1 hadoop]# ls /etc/h
hadoop/      hal/         hbase/       hive/        host.conf    hosts        hosts.allow  hosts.deny   httpd/       
[root@rhs-1 hadoop]# ls /etc/hadoop/conf
conf/        conf.empty/  conf.pseudo/ 
[root@rhs-1 hadoop]# ls /etc/hadoop/
conf  conf.empty  conf.pseudo
[root@rhs-1 hadoop]# ls /usr/lib/h
hadoop/ hbase/  hive/   
[root@rhs-1 hadoop]# ls /usr/lib/h
hadoop/ hbase/  hive/   
[root@rhs-1 hadoop]# ls /usr/lib/hadoop/
bin/                             hadoop-ant.jar                   hadoop-test.jar                  logs/                            restart.sh
build.xml                        hadoop-core-1.0.3-Intel.jar      hadoop-tools-1.0.3-Intel.jar     mapred/                          sbin/
CHANGES.txt                      hadoop-core.jar                  hadoop-tools.jar                 NOTICE.txt                       TestDFSIO_results.log
conf/                            hadoop-examples-1.0.3-Intel.jar  lib/                             pids/                            test.sh
contrib/                         hadoop-examples.jar              libexec/                         README.txt                       webapps/
hadoop-ant-1.0.3-Intel.jar       hadoop-test-1.0.3-Intel.jar      LICENSE.txt                      remount.sh                       
[root@rhs-1 hadoop]# ls /usr/lib/hadoop/
bin          contrib                      hadoop-core.jar                  hadoop-test.jar               libexec      NOTICE.txt  restart.sh             webapps
build.xml    hadoop-ant-1.0.3-Intel.jar   hadoop-examples-1.0.3-Intel.jar  hadoop-tools-1.0.3-Intel.jar  LICENSE.txt  pids        sbin
CHANGES.txt  hadoop-ant.jar               hadoop-examples.jar              hadoop-tools.jar              logs         README.txt  TestDFSIO_results.log
conf         hadoop-core-1.0.3-Intel.jar  hadoop-test-1.0.3-Intel.jar      lib                           mapred       remount.sh  test.sh
[root@rhs-1 hadoop]# ls /usr/lib/hadoop/lib
lib/     libexec/ 
[root@rhs-1 hadoop]# ls /usr/lib/hadoop/lib
0Aaglusterfs-0.20.20-0.1.jar      commons-digester-1.8.jar       guava-r09.jar                              jasper-runtime-5.5.12.jar      junit-4.5.jar
asm-3.2.jar                       commons-el-1.0.jar             hadoop-capacity-scheduler-1.0.3-Intel.jar  jdeb-0.8.jar                   kfs-0.2.2.jar
aspectjrt-1.6.5.jar               commons-httpclient-3.1.jar     hadoop-fairscheduler-1.0.3-Intel.jar       jdiff                          kfs-0.2.LICENSE.txt
aspectjtools-1.6.5.jar            commons-io-2.1.jar             hadoop-thriftfs-1.0.3-Intel.jar            jersey-core-1.8.jar            log4j-1.2.15.jar
commons-beanutils-1.7.0.jar       commons-lang-2.4.jar           hsqldb-1.8.0.10.jar                        jersey-json-1.8.jar            mockito-all-1.8.5.jar
commons-beanutils-core-1.8.0.jar  commons-logging-1.1.1.jar      hsqldb-1.8.0.10.LICENSE.txt                jersey-server-1.8.jar          native
commons-cli-1.2.jar               commons-logging-api-1.0.4.jar  jackson-core-asl-1.0.1.jar                 jets3t-0.6.1.jar               oro-2.0.8.jar
commons-codec-1.4.jar             commons-math-2.1.jar           jackson-core-asl-1.8.8.jar                 jetty-6.1.26.intel.1.jar       servlet-api-2.5-20081211.jar
commons-collections-3.2.1.jar     commons-net-1.4.1.jar          jackson-mapper-asl-1.0.1.jar               jetty-util-6.1.26.intel.1.jar  slf4j-api-1.4.3.jar
commons-configuration-1.6.jar     core-3.1.1.jar                 jackson-mapper-asl-1.8.8.jar               jsch-0.1.42.jar                slf4j-log4j12-1.4.3.jar
commons-daemon-1.0.1.jar          glusterfs-0.20.2-0.2.jar       jasper-compiler-5.5.12.jar                 jsp-2.1                        xmlenc-0.52.jar
[root@rhs-1 hadoop]# rm /usr/lib/hadoop/lib/0Aaglusterfs-0.20.20-0.1.jar 
rm: remove regular file `/usr/lib/hadoop/lib/0Aaglusterfs-0.20.20-0.1.jar'? y
[root@rhs-1 hadoop]# rm /mnt/glusterfs/
benchmarks/ tmp/        
[root@rhs-1 hadoop]# rm -rf /mnt/glusterfs/tmp/
[root@rhs-1 hadoop]# bin/hadoop jar hadoop-test-1.0.3-Intel.jar TestDFSIO -write -nrFiles 10 -fileSize 1
TestDFSIO.0.0.4
13/02/19 17:41:15 INFO fs.TestDFSIO: nrFiles = 10
13/02/19 17:41:15 INFO fs.TestDFSIO: fileSize (MB) = 1
13/02/19 17:41:15 INFO fs.TestDFSIO: bufferSize = 1000000
13/02/19 17:41:15 WARN conf.Configuration: mapred-site.xml:a attempt to override final parameter: mapred.local.dir;  Ignoring.
13/02/19 17:41:15 WARN conf.Configuration: mapred-site.xml:a attempt to override final parameter: mapred.local.dir;  Ignoring.
Initializing GlusterFS
13/02/19 17:41:15 INFO fs.TestDFSIO: creating control file: 1 mega bytes, 10 files
13/02/19 17:41:15 INFO fs.TestDFSIO: created control files for: 10 files
13/02/19 17:41:16 WARN conf.Configuration: mapred-site.xml:a attempt to override final parameter: mapred.local.dir;  Ignoring.
13/02/19 17:41:16 WARN conf.Configuration: mapred-site.xml:a attempt to override final parameter: mapred.local.dir;  Ignoring.
13/02/19 17:41:16 INFO mapred.FileInputFormat: Total input paths to process : 10
13/02/19 17:41:17 INFO mapred.JobClient: Running job: job_201302191737_0002
13/02/19 17:41:18 INFO mapred.JobClient:  map 0% reduce 0%
13/02/19 17:41:33 INFO mapred.JobClient:  map 10% reduce 0%
13/02/19 17:41:35 INFO mapred.JobClient:  map 20% reduce 0%
13/02/19 17:41:39 INFO mapred.JobClient:  map 40% reduce 0%
13/02/19 17:41:42 INFO mapred.JobClient:  map 50% reduce 0%
13/02/19 17:41:44 INFO mapred.JobClient:  map 60% reduce 16%
13/02/19 17:41:47 INFO mapred.JobClient:  map 70% reduce 16%
13/02/19 17:41:49 INFO mapred.JobClient:  map 80% reduce 16%
13/02/19 17:41:53 INFO mapred.JobClient:  map 80% reduce 23%
13/02/19 17:41:54 INFO mapred.JobClient:  map 90% reduce 23%
13/02/19 17:41:59 INFO mapred.JobClient:  map 100% reduce 30%
13/02/19 17:42:08 INFO mapred.JobClient:  map 100% reduce 100%
13/02/19 17:42:12 INFO mapred.JobClient: Job complete: job_201302191737_0002
13/02/19 17:42:12 INFO mapred.JobClient: Counters: 29
13/02/19 17:42:12 INFO mapred.JobClient:   Job Counters 
13/02/19 17:42:12 INFO mapred.JobClient:     Launched reduce tasks=1
13/02/19 17:42:12 INFO mapred.JobClient:     SLOTS_MILLIS_MAPS=68780
13/02/19 17:42:12 INFO mapred.JobClient:     Total time spent by all reduces waiting after reserving slots (ms)=0
13/02/19 17:42:12 INFO mapred.JobClient:     Total time spent by all maps waiting after reserving slots (ms)=0
13/02/19 17:42:12 INFO mapred.JobClient:     Rack-local map tasks=1
13/02/19 17:42:12 INFO mapred.JobClient:     Launched map tasks=10
13/02/19 17:42:12 INFO mapred.JobClient:     Data-local map tasks=9
13/02/19 17:42:12 INFO mapred.JobClient:     SLOTS_MILLIS_REDUCES=33607
13/02/19 17:42:12 INFO mapred.JobClient:   File Input Format Counters 
13/02/19 17:42:12 INFO mapred.JobClient:     Bytes Read=0
13/02/19 17:42:12 INFO mapred.JobClient:   File Output Format Counters 
13/02/19 17:42:12 INFO mapred.JobClient:     Bytes Written=0
13/02/19 17:42:12 INFO mapred.JobClient:   FileSystemCounters
13/02/19 17:42:12 INFO mapred.JobClient:     FILE_BYTES_READ=359
13/02/19 17:42:12 INFO mapred.JobClient:     FILE_BYTES_WRITTEN=274364
13/02/19 17:42:12 INFO mapred.JobClient:   Map-Reduce Framework
13/02/19 17:42:12 INFO mapred.JobClient:     Map output materialized bytes=939
13/02/19 17:42:12 INFO mapred.JobClient:     Map input records=10
13/02/19 17:42:12 INFO mapred.JobClient:     Reduce shuffle bytes=939
13/02/19 17:42:12 INFO mapred.JobClient:     Spilled Records=100
13/02/19 17:42:12 INFO mapred.JobClient:     Map output bytes=696
13/02/19 17:42:12 INFO mapred.JobClient:     Total committed heap usage (bytes)=1931190272
13/02/19 17:42:12 INFO mapred.JobClient:     CPU time spent (ms)=3650
13/02/19 17:42:12 INFO mapred.JobClient:     Map input bytes=260
13/02/19 17:42:12 INFO mapred.JobClient:     SPLIT_RAW_BYTES=-4445
13/02/19 17:42:12 INFO mapred.JobClient:     Combine input records=0
13/02/19 17:42:12 INFO mapred.JobClient:     Reduce input records=50
13/02/19 17:42:12 INFO mapred.JobClient:     Reduce input groups=5
13/02/19 17:42:12 INFO mapred.JobClient:     Combine output records=0
13/02/19 17:42:12 INFO mapred.JobClient:     Physical memory (bytes) snapshot=2318548992
13/02/19 17:42:12 INFO mapred.JobClient:     Reduce output records=5
13/02/19 17:42:12 INFO mapred.JobClient:     Virtual memory (bytes) snapshot=13713186816
13/02/19 17:42:12 INFO mapred.JobClient:     Map output records=50
java.io.IOException: Stream closed.
	at org.apache.hadoop.fs.glusterfs.GlusterFUSEInputStream.close(GlusterFUSEInputStream.java:184)
	at java.io.FilterInputStream.close(FilterInputStream.java:172)
	at java.io.FilterInputStream.close(FilterInputStream.java:172)
	at sun.nio.cs.StreamDecoder.implClose(StreamDecoder.java:376)
	at sun.nio.cs.StreamDecoder.close(StreamDecoder.java:191)
	at java.io.InputStreamReader.close(InputStreamReader.java:199)
	at java.io.BufferedReader.close(BufferedReader.java:514)
	at org.apache.hadoop.fs.TestDFSIO.analyzeResult(TestDFSIO.java:358)
	at org.apache.hadoop.fs.TestDFSIO.run(TestDFSIO.java:462)
	at org.apache.hadoop.util.ToolRunner.run(ToolRunner.java:65)
	at org.apache.hadoop.util.ToolRunner.run(ToolRunner.java:79)
	at org.apache.hadoop.fs.TestDFSIO.main(TestDFSIO.java:317)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:616)
	at org.apache.hadoop.util.ProgramDriver$ProgramDescription.invoke(ProgramDriver.java:68)
	at org.apache.hadoop.util.ProgramDriver.driver(ProgramDriver.java:139)
	at org.apache.hadoop.test.AllTestDriver.main(AllTestDriver.java:83)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:616)
	at org.apache.hadoop.util.RunJar.main(RunJar.java:187)
Comment 9 Jay Vyas 2013-03-05 17:17:03 UTC 
marking as modified instead of closed.
Note You need to log in before you can comment on or make changes to this bug.