07:08:34,006 INFO Test worker context.TestContextManager - @TestExecutionListeners is not present for class [class org.springframework.data.hadoop.fs.DistCpTest]: using defaults.
07:08:34,010 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/fs/DistCpTest-context.xml]
07:08:34,032 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/hadoop-ctx.xml]
07:08:34,088 INFO Test worker support.GenericApplicationContext - Refreshing org.springframework.context.support.GenericApplicationContext@37ed1dbe: startup date [Thu Sep 05 07:08:34 PDT 2013]; root of context hierarchy
07:08:34,120 INFO Test worker config.PropertyPlaceholderConfigurer - Loading properties file from class path resource [test.properties]
07:08:34,126 INFO Test worker support.DefaultListableBeanFactory - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@41e3a0ec: defining beans [ppc,hadoopFs,hadoopResourceLoader,hadoopConfiguration,cfg-init,fs-init,rl-init,org.springframework.data.hadoop.scripting.HdfsScriptRunner#0,org.springframework.context.annotation.internalConfigurationAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalRequiredAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor]; root of factory hierarchy
07:08:34,456 WARN Test worker util.NativeCodeLoader - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
07:08:34,456 WARN Test worker snappy.LoadSnappy - Snappy native library not loaded
hdfs://w1-kodiak-hd023:8020/user/bamboo/distcp/ae1e29ad-58a1-4197-a97d-25140d3fb3af
hdfs://w1-kodiak-hd023:8020/user/bamboo/distcp/dst
07:08:34,744 INFO Test worker tools.DistCp - srcPaths=[hdfs://w1-kodiak-hd023:8020/user/bamboo/distcp/ae1e29ad-58a1-4197-a97d-25140d3fb3af]
07:08:34,744 INFO Test worker tools.DistCp - destPath=hdfs://w1-kodiak-hd023:8020/user/bamboo/distcp/dst
07:08:35,231 INFO Test worker tools.DistCp - hdfs://w1-kodiak-hd023:8020/user/bamboo/distcp/dst does not exist.
07:08:35,279 INFO Test worker tools.DistCp - sourcePathsCount=1
07:08:35,279 INFO Test worker tools.DistCp - filesToCopyCount=1
07:08:35,280 INFO Test worker tools.DistCp - bytesToCopyCount=43.0
07:08:35,610 INFO Test worker mapred.JobClient - Running job: job_201308191125_0559
07:08:36,614 INFO Test worker mapred.JobClient - map 0% reduce 0%
07:08:41,627 INFO Test worker mapred.JobClient - map 100% reduce 0%
07:08:42,632 INFO Test worker mapred.JobClient - Job complete: job_201308191125_0559
07:08:42,660 INFO Test worker mapred.JobClient - Counters: 22
07:08:42,660 INFO Test worker mapred.JobClient - Job Counters
07:08:42,662 INFO Test worker mapred.JobClient - SLOTS_MILLIS_MAPS=5298
07:08:42,662 INFO Test worker mapred.JobClient - Total time spent by all reduces waiting after reserving slots (ms)=0
07:08:42,663 INFO Test worker mapred.JobClient - Total time spent by all maps waiting after reserving slots (ms)=0
07:08:42,663 INFO Test worker mapred.JobClient - Launched map tasks=1
07:08:42,664 INFO Test worker mapred.JobClient - SLOTS_MILLIS_REDUCES=0
07:08:42,664 INFO Test worker mapred.JobClient - File Input Format Counters
07:08:42,665 INFO Test worker mapred.JobClient - Bytes Read=292
07:08:42,665 INFO Test worker mapred.JobClient - File Output Format Counters
07:08:42,665 INFO Test worker mapred.JobClient - Bytes Written=0
07:08:42,666 INFO Test worker mapred.JobClient - FileSystemCounters
07:08:42,666 INFO Test worker mapred.JobClient - HDFS_BYTES_READ=492
07:08:42,667 INFO Test worker mapred.JobClient - FILE_BYTES_WRITTEN=54656
07:08:42,669 INFO Test worker mapred.JobClient - HDFS_BYTES_WRITTEN=43
07:08:42,669 INFO Test worker mapred.JobClient - distcp
07:08:42,670 INFO Test worker mapred.JobClient - Files copied=1
07:08:42,671 INFO Test worker mapred.JobClient - Bytes copied=43
07:08:42,671 INFO Test worker mapred.JobClient - Bytes expected=43
07:08:42,672 INFO Test worker mapred.JobClient - Map-Reduce Framework
07:08:42,672 INFO Test worker mapred.JobClient - Map input records=1
07:08:42,673 INFO Test worker mapred.JobClient - Physical memory (bytes) snapshot=114008064
07:08:42,674 INFO Test worker mapred.JobClient - Spilled Records=0
07:08:42,675 INFO Test worker mapred.JobClient - CPU time spent (ms)=350
07:08:42,675 INFO Test worker mapred.JobClient - Total committed heap usage (bytes)=76087296
07:08:42,676 INFO Test worker mapred.JobClient - Virtual memory (bytes) snapshot=838574080
07:08:42,677 INFO Test worker mapred.JobClient - Map input bytes=192
07:08:42,677 INFO Test worker mapred.JobClient - Map output records=0
07:08:42,677 INFO Test worker mapred.JobClient - SPLIT_RAW_BYTES=157
07:08:42,730 INFO Test worker tools.DistCp - srcPaths=[hdfs://w1-kodiak-hd023:8020/user/bamboo/distcp/3d53ae6f-8587-4ce9-bf31-60129fd973d6, hdfs://w1-kodiak-hd023:8020/user/bamboo/distcp/78b3c2c3-bfb7-4309-802d-c8080938852f]
07:08:42,731 INFO Test worker tools.DistCp - destPath=hdfs://w1-kodiak-hd023:8020/user/bamboo/distcp/dst
07:08:42,789 INFO Test worker tools.DistCp - hdfs://w1-kodiak-hd023:8020/user/bamboo/distcp/dst does not exist.
07:08:42,813 INFO Test worker tools.DistCp - sourcePathsCount=2
07:08:42,813 INFO Test worker tools.DistCp - filesToCopyCount=2
07:08:42,814 INFO Test worker tools.DistCp - bytesToCopyCount=86.0
07:08:42,997 INFO Test worker mapred.JobClient - Running job: job_201308191125_0560
07:08:43,998 INFO Test worker mapred.JobClient - map 0% reduce 0%
07:08:49,010 INFO Test worker mapred.JobClient - map 100% reduce 0%
07:08:50,015 INFO Test worker mapred.JobClient - Job complete: job_201308191125_0560
07:08:50,018 INFO Test worker mapred.JobClient - Counters: 22
07:08:50,018 INFO Test worker mapred.JobClient - Job Counters
07:08:50,018 INFO Test worker mapred.JobClient - SLOTS_MILLIS_MAPS=5946
07:08:50,018 INFO Test worker mapred.JobClient - Total time spent by all reduces waiting after reserving slots (ms)=0
07:08:50,019 INFO Test worker mapred.JobClient - Total time spent by all maps waiting after reserving slots (ms)=0
07:08:50,019 INFO Test worker mapred.JobClient - Launched map tasks=1
07:08:50,019 INFO Test worker mapred.JobClient - SLOTS_MILLIS_REDUCES=0
07:08:50,022 INFO Test worker mapred.JobClient - File Input Format Counters
07:08:50,023 INFO Test worker mapred.JobClient - Bytes Read=484
07:08:50,023 INFO Test worker mapred.JobClient - File Output Format Counters
07:08:50,023 INFO Test worker mapred.JobClient - Bytes Written=0
07:08:50,023 INFO Test worker mapred.JobClient - FileSystemCounters
07:08:50,024 INFO Test worker mapred.JobClient - HDFS_BYTES_READ=727
07:08:50,024 INFO Test worker mapred.JobClient - FILE_BYTES_WRITTEN=54660
07:08:50,024 INFO Test worker mapred.JobClient - HDFS_BYTES_WRITTEN=86
07:08:50,024 INFO Test worker mapred.JobClient - distcp
07:08:50,025 INFO Test worker mapred.JobClient - Files copied=2
07:08:50,025 INFO Test worker mapred.JobClient - Bytes copied=86
07:08:50,025 INFO Test worker mapred.JobClient - Bytes expected=86
07:08:50,025 INFO Test worker mapred.JobClient - Map-Reduce Framework
07:08:50,026 INFO Test worker mapred.JobClient - Map input records=2
07:08:50,026 INFO Test worker mapred.JobClient - Physical memory (bytes) snapshot=116244480
07:08:50,026 INFO Test worker mapred.JobClient - Spilled Records=0
07:08:50,026 INFO Test worker mapred.JobClient - CPU time spent (ms)=240
07:08:50,026 INFO Test worker mapred.JobClient - Total committed heap usage (bytes)=76087296
07:08:50,027 INFO Test worker mapred.JobClient - Virtual memory (bytes) snapshot=865443840
07:08:50,027 INFO Test worker mapred.JobClient - Map input bytes=384
07:08:50,027 INFO Test worker mapred.JobClient - Map output records=0
07:08:50,027 INFO Test worker mapred.JobClient - SPLIT_RAW_BYTES=157
hdfs://w1-kodiak-hd023:8020/user/bamboo/distcp/8221e76f-5a6a-4b65-beda-66f18276fcd6
hdfs://w1-kodiak-hd023:8020/user/bamboo/distcp/dst
07:08:50,293 INFO Test worker tools.DistCp - srcPaths=[hdfs://w1-kodiak-hd023:8020/user/bamboo/distcp/8221e76f-5a6a-4b65-beda-66f18276fcd6]
07:08:50,293 INFO Test worker tools.DistCp - destPath=hdfs://w1-kodiak-hd023:8020/user/bamboo/distcp/dst
07:08:50,344 INFO Test worker tools.DistCp - hdfs://w1-kodiak-hd023:8020/user/bamboo/distcp/dst does not exist.
07:08:50,362 INFO Test worker tools.DistCp - sourcePathsCount=1
07:08:50,362 INFO Test worker tools.DistCp - filesToCopyCount=1
07:08:50,362 INFO Test worker tools.DistCp - bytesToCopyCount=43.0
07:08:50,528 INFO Test worker mapred.JobClient - Running job: job_201308191125_0561
07:08:51,533 INFO Test worker mapred.JobClient - map 0% reduce 0%
07:08:56,544 INFO Test worker mapred.JobClient - map 100% reduce 0%
07:08:57,548 INFO Test worker mapred.JobClient - Job complete: job_201308191125_0561
07:08:57,552 INFO Test worker mapred.JobClient - Counters: 22
07:08:57,552 INFO Test worker mapred.JobClient - Job Counters
07:08:57,552 INFO Test worker mapred.JobClient - SLOTS_MILLIS_MAPS=5620
07:08:57,552 INFO Test worker mapred.JobClient - Total time spent by all reduces waiting after reserving slots (ms)=0
07:08:57,552 INFO Test worker mapred.JobClient - Total time spent by all maps waiting after reserving slots (ms)=0
07:08:57,552 INFO Test worker mapred.JobClient - Launched map tasks=1
07:08:57,553 INFO Test worker mapred.JobClient - SLOTS_MILLIS_REDUCES=0
07:08:57,553 INFO Test worker mapred.JobClient - File Input Format Counters
07:08:57,553 INFO Test worker mapred.JobClient - Bytes Read=292
07:08:57,553 INFO Test worker mapred.JobClient - File Output Format Counters
07:08:57,553 INFO Test worker mapred.JobClient - Bytes Written=0
07:08:57,553 INFO Test worker mapred.JobClient - FileSystemCounters
07:08:57,553 INFO Test worker mapred.JobClient - HDFS_BYTES_READ=492
07:08:57,553 INFO Test worker mapred.JobClient - FILE_BYTES_WRITTEN=54837
07:08:57,554 INFO Test worker mapred.JobClient - HDFS_BYTES_WRITTEN=43
07:08:57,554 INFO Test worker mapred.JobClient - distcp
07:08:57,554 INFO Test worker mapred.JobClient - Files copied=1
07:08:57,554 INFO Test worker mapred.JobClient - Bytes copied=43
07:08:57,554 INFO Test worker mapred.JobClient - Bytes expected=43
07:08:57,554 INFO Test worker mapred.JobClient - Map-Reduce Framework
07:08:57,554 INFO Test worker mapred.JobClient - Map input records=1
07:08:57,554 INFO Test worker mapred.JobClient - Physical memory (bytes) snapshot=114245632
07:08:57,555 INFO Test worker mapred.JobClient - Spilled Records=0
07:08:57,555 INFO Test worker mapred.JobClient - CPU time spent (ms)=200
07:08:57,555 INFO Test worker mapred.JobClient - Total committed heap usage (bytes)=76087296
07:08:57,555 INFO Test worker mapred.JobClient - Virtual memory (bytes) snapshot=840187904
07:08:57,555 INFO Test worker mapred.JobClient - Map input bytes=192
07:08:57,555 INFO Test worker mapred.JobClient - Map output records=0
07:08:57,555 INFO Test worker mapred.JobClient - SPLIT_RAW_BYTES=157