23:42:50,324 INFO Test worker context.TestContextManager - @TestExecutionListeners is not present for class [class org.springframework.data.hadoop.mapreduce.JobTests]: using defaults.
23:42:50,327 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/mapreduce/JobTests-context.xml]
23:42:50,399 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/hadoop-ctx.xml]
23:42:50,526 INFO Test worker support.GenericApplicationContext - Refreshing org.springframework.context.support.GenericApplicationContext@589dae25: startup date [Wed Sep 25 23:42:50 EDT 2013]; root of context hierarchy
23:42:50,597 INFO Test worker config.PropertyPlaceholderConfigurer - Loading properties file from class path resource [test.properties]
23:42:50,599 INFO Test worker annotation.AutowiredAnnotationBeanPostProcessor - JSR-330 'javax.inject.Inject' annotation found and supported for autowiring
23:42:50,601 INFO Test worker support.DefaultListableBeanFactory - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@4b1c5e8: defining beans [ppc,hadoopFs,hadoopResourceLoader,hadoopConfiguration,cfg-init,fs-init,rl-init,org.springframework.data.hadoop.scripting.HdfsScriptRunner#0,script,nop-script,jar-job-runner,another-runner,ns-runner,no-wait,jar-job,custom-jar-job,ns-job,executor,props,myScheduler,org.springframework.scheduling.support.MethodInvokingRunnable#0,org.springframework.scheduling.config.ScheduledTaskRegistrar#0,killer-runner,victim-job,async,org.springframework.context.annotation.internalConfigurationAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalRequiredAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor]; root of factory hierarchy
23:42:50,616 WARN Test worker conf.Configuration - fs.default.name is deprecated. Instead, use fs.defaultFS
23:42:50,644 INFO Test worker fs.TrashPolicyDefault - Namenode trash configuration: Deletion interval = 0 minutes, Emptier interval = 0 minutes.
23:42:50,661 INFO Test worker fs.TrashPolicyDefault - Namenode trash configuration: Deletion interval = 0 minutes, Emptier interval = 0 minutes.
23:42:50,680 INFO Test worker fs.TrashPolicyDefault - Namenode trash configuration: Deletion interval = 0 minutes, Emptier interval = 0 minutes.
23:42:51,110 INFO Test worker fs.TrashPolicyDefault - Namenode trash configuration: Deletion interval = 0 minutes, Emptier interval = 0 minutes.
Called script
23:42:51,179 INFO Test worker client.RMProxy - Connecting to ResourceManager at sandbox/172.16.87.151:8050
23:42:51,180 INFO Test worker mapreduce.JobRunner - Starting job [custom-jar-job]
23:42:51,194 INFO Test worker client.RMProxy - Connecting to ResourceManager at sandbox/172.16.87.151:8050
23:42:51,981 INFO Test worker input.FileInputFormat - Total input paths to process : 1
23:42:52,951 INFO Test worker mapreduce.JobSubmitter - number of splits:1
23:42:53,053 WARN Test worker conf.Configuration - mapred.jar is deprecated. Instead, use mapreduce.job.jar
23:42:53,053 WARN Test worker conf.Configuration - fs.default.name is deprecated. Instead, use fs.defaultFS
23:42:53,204 INFO Test worker mapreduce.JobSubmitter - Submitting tokens for job: job_1380140057116_0031
23:42:53,235 INFO Test worker impl.YarnClientImpl - Submitted application application_1380140057116_0031 to ResourceManager at sandbox/172.16.87.151:8050
23:42:53,239 INFO Test worker mapreduce.Job - The url to track the job: http://sandbox.hortonworks.com:8088/proxy/application_1380140057116_0031/
23:42:53,239 INFO Test worker mapreduce.Job - Running job: job_1380140057116_0031
23:42:59,637 INFO Test worker mapreduce.Job - Job job_1380140057116_0031 running in uber mode : false
23:42:59,637 INFO Test worker mapreduce.Job - map 0% reduce 0%
23:43:07,967 INFO Test worker mapreduce.Job - map 100% reduce 0%
23:43:13,299 INFO Test worker mapreduce.Job - map 100% reduce 100%
23:43:13,302 INFO Test worker mapreduce.Job - Job job_1380140057116_0031 completed successfully
23:43:13,351 INFO Test worker mapreduce.Job - Counters: 43
File System Counters
FILE: Number of bytes read=64
FILE: Number of bytes written=169131
FILE: Number of read operations=0
FILE: Number of large read operations=0
FILE: Number of write operations=0
HDFS: Number of bytes read=142
HDFS: Number of bytes written=38
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)=5367
Total time spent by all reduces in occupied slots (ms)=3725
Map-Reduce Framework
Map input records=3
Map output records=5
Map output bytes=48
Map output materialized bytes=64
Input split bytes=114
Combine input records=0
Combine output records=0
Reduce input groups=5
Reduce shuffle bytes=64
Reduce input records=5
Reduce output records=5
Spilled Records=10
Shuffled Maps =1
Failed Shuffles=0
Merged Map outputs=1
GC time elapsed (ms)=44
CPU time spent (ms)=1400
Physical memory (bytes) snapshot=375689216
Virtual memory (bytes) snapshot=2417594368
Total committed heap usage (bytes)=288686080
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=28
File Output Format Counters
Bytes Written=38
23:43:13,365 INFO Test worker mapreduce.JobRunner - Completed job [custom-jar-job]
23:43:13,368 INFO Test worker config.PropertiesFactoryBean - Loading properties file from class path resource [props.properties]
23:43:13,384 INFO Test worker config.PropertiesFactoryBean - Loading properties file from class path resource [cfg-1.properties]
23:43:13,385 INFO Test worker config.PropertiesFactoryBean - Loading properties file from class path resource [cfg-2.properties]
23:43:13,404 INFO Test worker concurrent.ThreadPoolTaskScheduler - Initializing ExecutorService 'myScheduler'
Called script
23:43:13,491 INFO myScheduler-1 client.RMProxy - Connecting to ResourceManager at sandbox/172.16.87.151:8050
23:43:13,492 INFO myScheduler-1 mapreduce.JobRunner - Starting job [custom-jar-job]
4