07:10:05,724 INFO Test worker context.TestContextManager - @TestExecutionListeners is not present for class [class org.springframework.data.hadoop.mapreduce.ToolTests]: using defaults.
07:10:05,728 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/mapreduce/ToolTests-context.xml]
07:10:05,782 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/hadoop-ctx.xml]
07:10:05,783 INFO myScheduler-1 mapred.JobClient - Cleaning up the staging area hdfs://w1-kodiak-hd023:8020/app/hadoop/tmp/mapred/staging/bamboo/.staging/job_201308191125_0566
07:10:05,786 ERROR myScheduler-1 security.UserGroupInformation - PriviledgedActionException as:bamboo cause:org.apache.hadoop.mapred.FileAlreadyExistsException: Output directory /ide-test/runner/output-4 already exists
07:10:05,787 WARN myScheduler-1 mapreduce.JobRunner - Cannot start job [custom-jar-job]
org.apache.hadoop.mapred.FileAlreadyExistsException: Output directory /ide-test/runner/output-4 already exists
at org.apache.hadoop.mapreduce.lib.output.FileOutputFormat.checkOutputSpecs(FileOutputFormat.java:137)
at org.apache.hadoop.mapred.JobClient$2.run(JobClient.java:973)
at org.apache.hadoop.mapred.JobClient$2.run(JobClient.java:936)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:416)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1190)
at org.apache.hadoop.mapred.JobClient.submitJobInternal(JobClient.java:936)
at org.apache.hadoop.mapreduce.Job.submit(Job.java:550)
at org.apache.hadoop.mapreduce.Job.waitForCompletion(Job.java:580)
at org.springframework.data.hadoop.mapreduce.JobExecutor$2.run(JobExecutor.java:201)
at org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:48)
at org.springframework.data.hadoop.mapreduce.JobExecutor.startJobs(JobExecutor.java:172)
at org.springframework.data.hadoop.mapreduce.JobExecutor.startJobs(JobExecutor.java:164)
at org.springframework.data.hadoop.mapreduce.JobRunner.call(JobRunner.java:52)
at org.springframework.data.hadoop.mapreduce.JobRunner.call(JobRunner.java:33)
at org.springframework.data.hadoop.mapreduce.JobRunner.invoke(JobRunner.java:88)
at org.springframework.data.hadoop.mapreduce.JobRunner.call(JobRunner.java:51)
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.springframework.util.MethodInvoker.invoke(MethodInvoker.java:273)
at org.springframework.scheduling.support.MethodInvokingRunnable.run(MethodInvokingRunnable.java:65)
at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:51)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
07:10:05,791 ERROR myScheduler-1 support.MethodInvokingRunnable - Invocation of method 'call' on target class [class org.springframework.data.hadoop.mapreduce.JobRunner] failed
java.lang.IllegalStateException: org.apache.hadoop.mapred.FileAlreadyExistsException: Output directory /ide-test/runner/output-4 already exists
at org.springframework.data.hadoop.mapreduce.JobExecutor$2.run(JobExecutor.java:213)
at org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:48)
at org.springframework.data.hadoop.mapreduce.JobExecutor.startJobs(JobExecutor.java:172)
at org.springframework.data.hadoop.mapreduce.JobExecutor.startJobs(JobExecutor.java:164)
at org.springframework.data.hadoop.mapreduce.JobRunner.call(JobRunner.java:52)
at org.springframework.data.hadoop.mapreduce.JobRunner.call(JobRunner.java:33)
at org.springframework.data.hadoop.mapreduce.JobRunner.invoke(JobRunner.java:88)
at org.springframework.data.hadoop.mapreduce.JobRunner.call(JobRunner.java:51)
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.springframework.util.MethodInvoker.invoke(MethodInvoker.java:273)
at org.springframework.scheduling.support.MethodInvokingRunnable.run(MethodInvokingRunnable.java:65)
at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:51)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:351)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:165)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:267)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1146)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:679)
Caused by: org.apache.hadoop.mapred.FileAlreadyExistsException: Output directory /ide-test/runner/output-4 already exists
at org.apache.hadoop.mapreduce.lib.output.FileOutputFormat.checkOutputSpecs(FileOutputFormat.java:137)
at org.apache.hadoop.mapred.JobClient$2.run(JobClient.java:973)
at org.apache.hadoop.mapred.JobClient$2.run(JobClient.java:936)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:416)
at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1190)
at org.apache.hadoop.mapred.JobClient.submitJobInternal(JobClient.java:936)
at org.apache.hadoop.mapreduce.Job.submit(Job.java:550)
at org.apache.hadoop.mapreduce.Job.waitForCompletion(Job.java:580)
at org.springframework.data.hadoop.mapreduce.JobExecutor$2.run(JobExecutor.java:201)
... 22 more
07:10:05,818 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/batch-common.xml]
07:10:05,838 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]
07:10:05,840 INFO Test worker support.GenericApplicationContext - Refreshing org.springframework.context.support.GenericApplicationContext@765a7159: startup date [Thu Sep 05 07:10:05 PDT 2013]; root of context hierarchy
07:10:05,858 INFO Test worker config.PropertyPlaceholderConfigurer - Loading properties file from class path resource [test.properties]
07:10:05,870 INFO Test worker support.DefaultListableBeanFactory - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@157dd1d1: defining beans [ppc,hadoopFs,hadoopResourceLoader,hadoopConfiguration,cfg-init,fs-init,rl-init,org.springframework.data.hadoop.scripting.HdfsScriptRunner#0,jobRepository,transactionManager,jobLauncher,taskExecutor,simple,test-tool,ref,ref-start,nested,org.springframework.batch.core.scope.internalStepScope,org.springframework.beans.factory.config.CustomEditorConfigurer,org.springframework.batch.core.configuration.xml.CoreNamespacePostProcessor,bean,ns,mainJob,tasklet,tasklet-ns,tool-jar,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:10:06,022 INFO Test worker mapreduce.ToolRunner - Invoking [org.springframework.data.hadoop.mapreduce.ToolTests$TestTool@6807299a] with args [[]]
07:10:06,078 INFO Test worker support.SimpleJobLauncher - Job: [FlowJob: [name=mainJob]] launched with the following parameters: [{}]
07:10:06,092 INFO Test worker job.SimpleStepHandler - Executing step: [bean]
07:10:06,097 INFO Test worker mapreduce.ToolTasklet - Invoking [org.springframework.data.hadoop.mapreduce.ToolTests$TestTool@6807299a] with args [null]
07:10:06,125 INFO Test worker job.SimpleStepHandler - Executing step: [ns]
07:10:06,131 INFO Test worker mapreduce.ToolTasklet - Invoking [org.springframework.data.hadoop.mapreduce.ToolTests$TestTool@304b0cbc] with args [[]]
07:10:06,154 INFO Test worker support.SimpleJobLauncher - Job: [FlowJob: [name=mainJob]] completed with the following parameters: [{}] and the following status: [COMPLETED]
07:10:06,155 INFO Test worker support.GenericApplicationContext - Closing org.springframework.context.support.GenericApplicationContext@765a7159: startup date [Thu Sep 05 07:10:05 PDT 2013]; root of context hierarchy
07:10:06,155 INFO Test worker support.DefaultListableBeanFactory - Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@157dd1d1: defining beans [ppc,hadoopFs,hadoopResourceLoader,hadoopConfiguration,cfg-init,fs-init,rl-init,org.springframework.data.hadoop.scripting.HdfsScriptRunner#0,jobRepository,transactionManager,jobLauncher,taskExecutor,simple,test-tool,ref,ref-start,nested,org.springframework.batch.core.scope.internalStepScope,org.springframework.beans.factory.config.CustomEditorConfigurer,org.springframework.batch.core.configuration.xml.CoreNamespacePostProcessor,bean,ns,mainJob,tasklet,tasklet-ns,tool-jar,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:10:06,162 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/mapreduce/ToolTests-context.xml]
07:10:06,201 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/hadoop-ctx.xml]
07:10:06,230 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/batch-common.xml]
07:10:06,247 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]
07:10:06,249 INFO Test worker support.GenericApplicationContext - Refreshing org.springframework.context.support.GenericApplicationContext@a5ab328: startup date [Thu Sep 05 07:10:06 PDT 2013]; root of context hierarchy
07:10:06,264 INFO Test worker config.PropertyPlaceholderConfigurer - Loading properties file from class path resource [test.properties]
07:10:06,276 INFO Test worker support.DefaultListableBeanFactory - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@6483f3a0: defining beans [ppc,hadoopFs,hadoopResourceLoader,hadoopConfiguration,cfg-init,fs-init,rl-init,org.springframework.data.hadoop.scripting.HdfsScriptRunner#0,jobRepository,transactionManager,jobLauncher,taskExecutor,simple,test-tool,ref,ref-start,nested,org.springframework.batch.core.scope.internalStepScope,org.springframework.beans.factory.config.CustomEditorConfigurer,org.springframework.batch.core.configuration.xml.CoreNamespacePostProcessor,bean,ns,mainJob,tasklet,tasklet-ns,tool-jar,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:10:06,340 INFO Test worker mapreduce.ToolRunner - Invoking [org.springframework.data.hadoop.mapreduce.ToolTests$TestTool@ee7c921] with args [[]]
07:10:06,372 INFO Test worker support.GenericApplicationContext - Closing org.springframework.context.support.GenericApplicationContext@a5ab328: startup date [Thu Sep 05 07:10:06 PDT 2013]; root of context hierarchy
07:10:06,373 INFO Test worker support.DefaultListableBeanFactory - Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@6483f3a0: defining beans [ppc,hadoopFs,hadoopResourceLoader,hadoopConfiguration,cfg-init,fs-init,rl-init,org.springframework.data.hadoop.scripting.HdfsScriptRunner#0,jobRepository,transactionManager,jobLauncher,taskExecutor,simple,test-tool,ref,ref-start,nested,org.springframework.batch.core.scope.internalStepScope,org.springframework.beans.factory.config.CustomEditorConfigurer,org.springframework.batch.core.configuration.xml.CoreNamespacePostProcessor,bean,ns,mainJob,tasklet,tasklet-ns,tool-jar,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:10:06,383 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/mapreduce/ToolTests-context.xml]
07:10:06,420 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/hadoop-ctx.xml]
07:10:06,458 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/batch-common.xml]
07:10:06,474 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]
07:10:06,476 INFO Test worker support.GenericApplicationContext - Refreshing org.springframework.context.support.GenericApplicationContext@201d04d6: startup date [Thu Sep 05 07:10:06 PDT 2013]; root of context hierarchy
07:10:06,491 INFO Test worker config.PropertyPlaceholderConfigurer - Loading properties file from class path resource [test.properties]
07:10:06,503 INFO Test worker support.DefaultListableBeanFactory - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@fc93f91: defining beans [ppc,hadoopFs,hadoopResourceLoader,hadoopConfiguration,cfg-init,fs-init,rl-init,org.springframework.data.hadoop.scripting.HdfsScriptRunner#0,jobRepository,transactionManager,jobLauncher,taskExecutor,simple,test-tool,ref,ref-start,nested,org.springframework.batch.core.scope.internalStepScope,org.springframework.beans.factory.config.CustomEditorConfigurer,org.springframework.batch.core.configuration.xml.CoreNamespacePostProcessor,bean,ns,mainJob,tasklet,tasklet-ns,tool-jar,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:10:06,568 INFO Test worker mapreduce.ToolRunner - Invoking [org.springframework.data.hadoop.mapreduce.ToolTests$TestTool@da69a9c] with args [[]]
07:10:06,602 INFO Test worker support.GenericApplicationContext - Closing org.springframework.context.support.GenericApplicationContext@201d04d6: startup date [Thu Sep 05 07:10:06 PDT 2013]; root of context hierarchy
07:10:06,603 INFO Test worker support.DefaultListableBeanFactory - Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@fc93f91: defining beans [ppc,hadoopFs,hadoopResourceLoader,hadoopConfiguration,cfg-init,fs-init,rl-init,org.springframework.data.hadoop.scripting.HdfsScriptRunner#0,jobRepository,transactionManager,jobLauncher,taskExecutor,simple,test-tool,ref,ref-start,nested,org.springframework.batch.core.scope.internalStepScope,org.springframework.beans.factory.config.CustomEditorConfigurer,org.springframework.batch.core.configuration.xml.CoreNamespacePostProcessor,bean,ns,mainJob,tasklet,tasklet-ns,tool-jar,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:10:06,608 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/mapreduce/ToolTests-context.xml]
07:10:06,646 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/hadoop-ctx.xml]
07:10:06,673 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/batch-common.xml]
07:10:06,689 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]
07:10:06,691 INFO Test worker support.GenericApplicationContext - Refreshing org.springframework.context.support.GenericApplicationContext@45cebcf0: startup date [Thu Sep 05 07:10:06 PDT 2013]; root of context hierarchy
07:10:06,704 INFO Test worker config.PropertyPlaceholderConfigurer - Loading properties file from class path resource [test.properties]
07:10:06,715 INFO Test worker support.DefaultListableBeanFactory - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@41607b27: defining beans [ppc,hadoopFs,hadoopResourceLoader,hadoopConfiguration,cfg-init,fs-init,rl-init,org.springframework.data.hadoop.scripting.HdfsScriptRunner#0,jobRepository,transactionManager,jobLauncher,taskExecutor,simple,test-tool,ref,ref-start,nested,org.springframework.batch.core.scope.internalStepScope,org.springframework.beans.factory.config.CustomEditorConfigurer,org.springframework.batch.core.configuration.xml.CoreNamespacePostProcessor,bean,ns,mainJob,tasklet,tasklet-ns,tool-jar,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:10:06,784 INFO Test worker mapreduce.ToolRunner - Invoking [org.springframework.data.hadoop.mapreduce.ToolTests$TestTool@55a729c1] with args [[]]
07:10:06,814 INFO Test worker mapreduce.ToolRunner - Invoking [org.springframework.data.hadoop.mapreduce.ToolTests$TestTool@577f5229] with args [[--local, data/in.txt, data/out.txt]]
07:10:06,815 INFO Test worker support.GenericApplicationContext - Closing org.springframework.context.support.GenericApplicationContext@45cebcf0: startup date [Thu Sep 05 07:10:06 PDT 2013]; root of context hierarchy
07:10:06,815 INFO Test worker support.DefaultListableBeanFactory - Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@41607b27: defining beans [ppc,hadoopFs,hadoopResourceLoader,hadoopConfiguration,cfg-init,fs-init,rl-init,org.springframework.data.hadoop.scripting.HdfsScriptRunner#0,jobRepository,transactionManager,jobLauncher,taskExecutor,simple,test-tool,ref,ref-start,nested,org.springframework.batch.core.scope.internalStepScope,org.springframework.beans.factory.config.CustomEditorConfigurer,org.springframework.batch.core.configuration.xml.CoreNamespacePostProcessor,bean,ns,mainJob,tasklet,tasklet-ns,tool-jar,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:10:06,821 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/mapreduce/ToolTests-context.xml]
07:10:06,857 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/hadoop-ctx.xml]
07:10:06,884 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/batch-common.xml]
07:10:06,900 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]
07:10:06,902 INFO Test worker support.GenericApplicationContext - Refreshing org.springframework.context.support.GenericApplicationContext@64cbdef5: startup date [Thu Sep 05 07:10:06 PDT 2013]; root of context hierarchy
07:10:06,915 INFO Test worker config.PropertyPlaceholderConfigurer - Loading properties file from class path resource [test.properties]
07:10:06,927 INFO Test worker support.DefaultListableBeanFactory - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@7c883540: defining beans [ppc,hadoopFs,hadoopResourceLoader,hadoopConfiguration,cfg-init,fs-init,rl-init,org.springframework.data.hadoop.scripting.HdfsScriptRunner#0,jobRepository,transactionManager,jobLauncher,taskExecutor,simple,test-tool,ref,ref-start,nested,org.springframework.batch.core.scope.internalStepScope,org.springframework.beans.factory.config.CustomEditorConfigurer,org.springframework.batch.core.configuration.xml.CoreNamespacePostProcessor,bean,ns,mainJob,tasklet,tasklet-ns,tool-jar,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:10:06,986 INFO Test worker mapreduce.ToolRunner - Invoking [org.springframework.data.hadoop.mapreduce.ToolTests$TestTool@37a63e06] with args [[]]
07:10:07,022 INFO Test worker support.GenericApplicationContext - Closing org.springframework.context.support.GenericApplicationContext@64cbdef5: startup date [Thu Sep 05 07:10:06 PDT 2013]; root of context hierarchy
07:10:07,022 INFO Test worker support.DefaultListableBeanFactory - Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@7c883540: defining beans [ppc,hadoopFs,hadoopResourceLoader,hadoopConfiguration,cfg-init,fs-init,rl-init,org.springframework.data.hadoop.scripting.HdfsScriptRunner#0,jobRepository,transactionManager,jobLauncher,taskExecutor,simple,test-tool,ref,ref-start,nested,org.springframework.batch.core.scope.internalStepScope,org.springframework.beans.factory.config.CustomEditorConfigurer,org.springframework.batch.core.configuration.xml.CoreNamespacePostProcessor,bean,ns,mainJob,tasklet,tasklet-ns,tool-jar,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:10:07,027 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/mapreduce/ToolTests-context.xml]
07:10:07,063 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/hadoop-ctx.xml]
07:10:07,089 INFO Test worker xml.XmlBeanDefinitionReader - Loading XML bean definitions from class path resource [org/springframework/data/hadoop/batch-common.xml]
07:10:07,105 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]
07:10:07,106 INFO Test worker support.GenericApplicationContext - Refreshing org.springframework.context.support.GenericApplicationContext@3d8b697e: startup date [Thu Sep 05 07:10:07 PDT 2013]; root of context hierarchy
07:10:07,119 INFO Test worker config.PropertyPlaceholderConfigurer - Loading properties file from class path resource [test.properties]
07:10:07,129 INFO Test worker support.DefaultListableBeanFactory - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@f970646: defining beans [ppc,hadoopFs,hadoopResourceLoader,hadoopConfiguration,cfg-init,fs-init,rl-init,org.springframework.data.hadoop.scripting.HdfsScriptRunner#0,jobRepository,transactionManager,jobLauncher,taskExecutor,simple,test-tool,ref,ref-start,nested,org.springframework.batch.core.scope.internalStepScope,org.springframework.beans.factory.config.CustomEditorConfigurer,org.springframework.batch.core.configuration.xml.CoreNamespacePostProcessor,bean,ns,mainJob,tasklet,tasklet-ns,tool-jar,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:10:07,188 INFO Test worker mapreduce.ToolRunner - Invoking [org.springframework.data.hadoop.mapreduce.ToolTests$TestTool@50cf99e8] with args [[]]
07:10:07,223 INFO Test worker mapreduce.ToolRunner - Invoking [test.SomeTool@6ebe20a] from jar [file:/data/bamboo-home/xml-data/build-dir/SPRINGDATAHADOOP-HDP13CENTOS0-JOB1/build/resources/test/some-tool.jar] with args [[13]]
07:10:07,276 INFO Test worker input.FileInputFormat - Total input paths to process : 1
07:10:07,378 INFO Test worker mapred.JobClient - Running job: job_201308191125_0567
07:10:08,380 INFO Test worker mapred.JobClient - map 0% reduce 0%
07:10:13,389 INFO Test worker mapred.JobClient - map 100% reduce 0%
07:10:20,402 INFO Test worker mapred.JobClient - map 100% reduce 33%
07:10:21,404 INFO Test worker mapred.JobClient - map 100% reduce 100%
07:10:22,409 INFO Test worker mapred.JobClient - Job complete: job_201308191125_0567
07:10:22,412 INFO Test worker mapred.JobClient - Counters: 29
07:10:22,412 INFO Test worker mapred.JobClient - Job Counters
07:10:22,412 INFO Test worker mapred.JobClient - Launched reduce tasks=1
07:10:22,412 INFO Test worker mapred.JobClient - SLOTS_MILLIS_MAPS=5455
07:10:22,412 INFO Test worker mapred.JobClient - Total time spent by all reduces waiting after reserving slots (ms)=0
07:10:22,412 INFO Test worker mapred.JobClient - Total time spent by all maps waiting after reserving slots (ms)=0
07:10:22,412 INFO Test worker mapred.JobClient - Launched map tasks=1
07:10:22,412 INFO Test worker mapred.JobClient - Data-local map tasks=1
07:10:22,412 INFO Test worker mapred.JobClient - SLOTS_MILLIS_REDUCES=8305
07:10:22,412 INFO Test worker mapred.JobClient - File Output Format Counters
07:10:22,412 INFO Test worker mapred.JobClient - Bytes Written=38
07:10:22,413 INFO Test worker mapred.JobClient - FileSystemCounters
07:10:22,413 INFO Test worker mapred.JobClient - FILE_BYTES_READ=64
07:10:22,413 INFO Test worker mapred.JobClient - HDFS_BYTES_READ=150
07:10:22,413 INFO Test worker mapred.JobClient - FILE_BYTES_WRITTEN=110131
07:10:22,413 INFO Test worker mapred.JobClient - HDFS_BYTES_WRITTEN=38
07:10:22,413 INFO Test worker mapred.JobClient - File Input Format Counters
07:10:22,413 INFO Test worker mapred.JobClient - Bytes Read=28
07:10:22,413 INFO Test worker mapred.JobClient - Map-Reduce Framework
07:10:22,413 INFO Test worker mapred.JobClient - Map output materialized bytes=64
07:10:22,413 INFO Test worker mapred.JobClient - Map input records=3
07:10:22,414 INFO Test worker mapred.JobClient - Reduce shuffle bytes=64
07:10:22,414 INFO Test worker mapred.JobClient - Spilled Records=10
07:10:22,414 INFO Test worker mapred.JobClient - Map output bytes=48
07:10:22,414 INFO Test worker mapred.JobClient - CPU time spent (ms)=1440
07:10:22,414 INFO Test worker mapred.JobClient - Total committed heap usage (bytes)=239075328
07:10:22,414 INFO Test worker mapred.JobClient - Combine input records=0
07:10:22,414 INFO Test worker mapred.JobClient - SPLIT_RAW_BYTES=122
07:10:22,414 INFO Test worker mapred.JobClient - Reduce input records=5
07:10:22,414 INFO Test worker mapred.JobClient - Reduce input groups=5
07:10:22,414 INFO Test worker mapred.JobClient - Combine output records=0
07:10:22,414 INFO Test worker mapred.JobClient - Physical memory (bytes) snapshot=323883008
07:10:22,415 INFO Test worker mapred.JobClient - Reduce output records=5
07:10:22,415 INFO Test worker mapred.JobClient - Virtual memory (bytes) snapshot=1699119104
07:10:22,415 INFO Test worker mapred.JobClient - Map output records=5
Loading classes ...
07:10:24,906 INFO Test worker support.GenericApplicationContext - Closing org.springframework.context.support.GenericApplicationContext@3d8b697e: startup date [Thu Sep 05 07:10:07 PDT 2013]; root of context hierarchy
07:10:24,906 INFO Test worker support.DefaultListableBeanFactory - Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@f970646: defining beans [ppc,hadoopFs,hadoopResourceLoader,hadoopConfiguration,cfg-init,fs-init,rl-init,org.springframework.data.hadoop.scripting.HdfsScriptRunner#0,jobRepository,transactionManager,jobLauncher,taskExecutor,simple,test-tool,ref,ref-start,nested,org.springframework.batch.core.scope.internalStepScope,org.springframework.beans.factory.config.CustomEditorConfigurer,org.springframework.batch.core.configuration.xml.CoreNamespacePostProcessor,bean,ns,mainJob,tasklet,tasklet-ns,tool-jar,org.springframework.context.annotation.internalConfigurationAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalRequiredAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor]; root of factory hierarchy