23:42:03,890 INFO Test worker support.ClassPathXmlApplicationContext - Refreshing org.springframework.context.support.ClassPathXmlApplicationContext@6b3a24e4: startup date [Wed Sep 25 23:42:03 EDT 2013]; root of context hierarchy
23:42:03,890 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/fs/HdfsItemWriterTest-context.xml]
23:42:04,376 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/batch-common.xml]
23:42:04,467 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/hadoop-ctx.xml]
23:42:04,509 INFO Test worker support.DefaultListableBeanFactory - Overriding bean definition for bean 'mainJob': replacing [Generic bean: class [org.springframework.batch.core.configuration.xml.SimpleFlowFactoryBean]; scope=; abstract=false; lazyInit=false; autowireMode=0; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=null; factoryMethodName=null; initMethodName=null; destroyMethodName=null] with [Generic bean: class [org.springframework.batch.core.configuration.xml.JobParserJobFactoryBean]; scope=; abstract=false; lazyInit=false; autowireMode=0; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=null; factoryMethodName=null; initMethodName=null; destroyMethodName=null]
23:42:04,521 INFO Test worker config.PropertyPlaceholderConfigurer - Loading properties file from class path resource [test.properties]
23:42:04,532 INFO Test worker support.DefaultListableBeanFactory - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@744cf1e3: defining beans [jobRepository,transactionManager,jobLauncher,taskExecutor,ppc,hadoopFs,hadoopResourceLoader,hadoopConfiguration,cfg-init,fs-init,rl-init,org.springframework.data.hadoop.scripting.HdfsScriptRunner#0,org.springframework.batch.core.scope.internalStepScope,org.springframework.beans.factory.config.CustomEditorConfigurer,org.springframework.batch.core.configuration.xml.CoreNamespacePostProcessor,import,do,org.springframework.data.hadoop.scripting.HdfsScriptRunner#1,script-tasklet,clean,mainJob,itemReader,hdfsItemWriter,hadoop-tasklet,mr-job]; root of factory hierarchy
23:42:04,697 WARN Test worker conf.Configuration - fs.default.name is deprecated. Instead, use fs.defaultFS
23:42:04,720 INFO Test worker fs.TrashPolicyDefault - Namenode trash configuration: Deletion interval = 0 minutes, Emptier interval = 0 minutes.
23:42:04,740 INFO Test worker fs.TrashPolicyDefault - Namenode trash configuration: Deletion interval = 0 minutes, Emptier interval = 0 minutes.
23:42:04,742 INFO Test worker fs.TrashPolicyDefault - Namenode trash configuration: Deletion interval = 0 minutes, Emptier interval = 0 minutes.
23:42:04,743 INFO Test worker fs.TrashPolicyDefault - Namenode trash configuration: Deletion interval = 0 minutes, Emptier interval = 0 minutes.
23:42:04,786 INFO Test worker support.SimpleJobLauncher - Job: [FlowJob: [name=mainJob]] launched with the following parameters: [{}]
23:42:04,795 INFO Test worker job.SimpleStepHandler - Executing step: [import]
23:42:04,845 INFO Test worker job.SimpleStepHandler - Executing step: [do]
23:42:04,870 INFO Test worker client.RMProxy - Connecting to ResourceManager at sandbox/172.16.87.151:8050
23:42:04,872 INFO Test worker mapreduce.JobTasklet - Starting job [mr-job]
23:42:04,910 INFO Test worker client.RMProxy - Connecting to ResourceManager at sandbox/172.16.87.151:8050
23:42:05,148 INFO Test worker input.FileInputFormat - Total input paths to process : 1
23:42:05,186 INFO Test worker mapreduce.JobSubmitter - number of splits:1
23:42:05,197 WARN Test worker conf.Configuration - fs.default.name is deprecated. Instead, use fs.defaultFS
23:42:05,229 INFO Test worker mapreduce.JobSubmitter - Submitting tokens for job: job_1380140057116_0028
23:42:05,252 INFO Test worker impl.YarnClientImpl - Submitted application application_1380140057116_0028 to ResourceManager at sandbox/172.16.87.151:8050
23:42:05,255 INFO Test worker mapreduce.Job - The url to track the job: http://sandbox.hortonworks.com:8088/proxy/application_1380140057116_0028/
23:42:05,255 INFO Test worker mapreduce.Job - Running job: job_1380140057116_0028
23:42:12,641 INFO Test worker mapreduce.Job - Job job_1380140057116_0028 running in uber mode : false
23:42:12,641 INFO Test worker mapreduce.Job - map 0% reduce 0%
23:42:17,894 INFO Test worker mapreduce.Job - map 100% reduce 0%
23:42:24,013 INFO Test worker mapreduce.Job - map 100% reduce 100%
23:42:24,020 INFO Test worker mapreduce.Job - Job job_1380140057116_0028 completed successfully
23:42:24,055 INFO Test worker mapreduce.Job - Counters: 43
File System Counters
FILE: Number of bytes read=477
FILE: Number of bytes written=166571
FILE: Number of read operations=0
FILE: Number of large read operations=0
FILE: Number of write operations=0
HDFS: Number of bytes read=388
HDFS: Number of bytes written=345
HDFS: Number of read operations=6
HDFS: Number of large read operations=0
HDFS: Number of write operations=2
Job Counters
Launched map tasks=1
Launched reduce tasks=1
Data-local map tasks=1
Total time spent by all maps in occupied slots (ms)=3816
Total time spent by all reduces in occupied slots (ms)=4261
Map-Reduce Framework
Map input records=6
Map output records=25
Map output bytes=421
Map output materialized bytes=477
Input split bytes=108
Combine input records=0
Combine output records=0
Reduce input groups=21
Reduce shuffle bytes=477
Reduce input records=25
Reduce output records=21
Spilled Records=50
Shuffled Maps =1
Failed Shuffles=0
Merged Map outputs=1
GC time elapsed (ms)=59
CPU time spent (ms)=1770
Physical memory (bytes) snapshot=365551616
Virtual memory (bytes) snapshot=2424283136
Total committed heap usage (bytes)=257097728
Shuffle Errors
BAD_ID=0
CONNECTION=0
IO_ERROR=0
WRONG_LENGTH=0
WRONG_MAP=0
WRONG_REDUCE=0
File Input Format Counters
Bytes Read=280
File Output Format Counters
Bytes Written=345
23:42:24,062 INFO Test worker mapreduce.JobTasklet - Completed job [mr-job]
23:42:24,180 INFO Test worker client.RMProxy - Connecting to ResourceManager at sandbox/172.16.87.151:8050
23:42:24,317 INFO Test worker job.SimpleStepHandler - Executing step: [clean]
23:42:24,338 INFO Test worker fs.TrashPolicyDefault - Namenode trash configuration: Deletion interval = 0 minutes, Emptier interval = 0 minutes.
23:42:24,350 INFO Test worker support.SimpleJobLauncher - Job: [FlowJob: [name=mainJob]] completed with the following parameters: [{}] and the following status: [COMPLETED]