2015-02-10 21:46:05,648 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2015-02-10 21:46:05,722 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop2-mr1
2015-02-10 21:46:05,723 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.RegressionPipesPlatformTest
2015-02-10 21:46:05,767 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(105)) - not using cluster
2015-02-10 21:46:06,440 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2015-02-10 21:46:06,785 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 21:46:06,788 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-10 21:46:06,802 INFO property.AppProps (AppProps.java:getAppID(169)) - using app.id: 158A4FD99C6545EAA99EF643F600B1AE
2015-02-10 21:46:06,886 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:06,942 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:06,946 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 21:46:07,086 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 2.6.3
2015-02-10 21:46:07,088 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 21:46:07,089 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lhs.txt"]
2015-02-10 21:46:07,090 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicor"]
2015-02-10 21:46:07,090 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 21:46:07,092 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 21:46:07,092 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 21:46:07,094 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...regression/complexlogicor
2015-02-10 21:46:07,118 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - session.id is deprecated. Instead, use dfs.metrics.session-id
2015-02-10 21:46:07,120 INFO jvm.JvmMetrics (JvmMetrics.java:init(76)) - Initializing JVM Metrics with processName=JobTracker, sessionId=
2015-02-10 21:46:07,143 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:07,526 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:07,568 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 21:46:07,741 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1075188504_0001
2015-02-10 21:46:07,782 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity1075188504/.staging/job_local1075188504_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:07,793 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity1075188504/.staging/job_local1075188504_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:07,982 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1075188504_0001/job_local1075188504_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:07,989 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1075188504_0001/job_local1075188504_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:07,995 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:07,997 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:08,000 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1075188504_0001
2015-02-10 21:46:08,000 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 21:46:08,001 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:08,063 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:08,066 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1075188504_0001_m_000000_0
2015-02-10 21:46:08,111 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:08,121 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lhs.txt
2015-02-10 21:46:08,122 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@76136c55
2015-02-10 21:46:08,131 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 21:46:08,149 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:08,149 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:08,196 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.task.partition is deprecated. Instead, use mapreduce.task.partition
2015-02-10 21:46:08,205 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lhs.txt"]
2015-02-10 21:46:08,206 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicor"]
2015-02-10 21:46:08,227 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:08,227 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1075188504_0001_m_000000_0 is done. And is in the process of committing
2015-02-10 21:46:08,236 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:08,237 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1075188504_0001_m_000000_0 is allowed to commit now
2015-02-10 21:46:08,238 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1075188504_0001_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicor/_temporary/0/task_local1075188504_0001_m_000000
2015-02-10 21:46:08,240 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lhs.txt:0+52
2015-02-10 21:46:08,240 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1075188504_0001_m_000000_0' done.
2015-02-10 21:46:08,241 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1075188504_0001_m_000000_0
2015-02-10 21:46:08,241 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:08,290 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicor/_temporary
2015-02-10 21:46:08,351 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:08,357 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/regression/complexlogicor
2015-02-10 21:46:08,392 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 21:46:08,393 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-10 21:46:08,408 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:08,415 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:08,416 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 21:46:08,428 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] starting
2015-02-10 21:46:08,428 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower.txt"]
2015-02-10 21:46:08,429 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/intermediate"]
2015-02-10 21:46:08,429 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] parallel execution is enabled: false
2015-02-10 21:46:08,429 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] starting jobs: 1
2015-02-10 21:46:08,430 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] allocating threads: 1
2015-02-10 21:46:08,430 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [split] starting step: (1/1) ...ipesplatform/intermediate
2015-02-10 21:46:08,431 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:08,433 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:08,466 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:08,490 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 21:46:08,574 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local794516570_0002
2015-02-10 21:46:08,599 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity794516570/.staging/job_local794516570_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:08,602 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity794516570/.staging/job_local794516570_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:08,738 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local794516570_0002/job_local794516570_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:08,741 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local794516570_0002/job_local794516570_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:08,742 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:08,742 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [split] submitted hadoop job: job_local794516570_0002
2015-02-10 21:46:08,743 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:08,743 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [split] tracking url: http://localhost:8080/
2015-02-10 21:46:08,743 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:08,748 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:08,749 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local794516570_0002_m_000000_0
2015-02-10 21:46:08,753 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:08,756 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower.txt
2015-02-10 21:46:08,756 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@7640d611
2015-02-10 21:46:08,759 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 21:46:08,770 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:08,771 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:08,789 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower.txt"]
2015-02-10 21:46:08,789 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/intermediate"]
2015-02-10 21:46:08,793 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:08,794 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local794516570_0002_m_000000_0 is done. And is in the process of committing
2015-02-10 21:46:08,796 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:08,796 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local794516570_0002_m_000000_0 is allowed to commit now
2015-02-10 21:46:08,797 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local794516570_0002_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/intermediate/_temporary/0/task_local794516570_0002_m_000000
2015-02-10 21:46:08,799 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower.txt:0+19
2015-02-10 21:46:08,799 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local794516570_0002_m_000000_0' done.
2015-02-10 21:46:08,799 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local794516570_0002_m_000000_0
2015-02-10 21:46:08,800 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:08,822 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/intermediate/_temporary
2015-02-10 21:46:08,866 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 21:46:08,867 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-10 21:46:08,895 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:08,900 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:08,901 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 21:46:08,928 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs*rhs] starting
2015-02-10 21:46:08,928 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs*rhs] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/intermediate"]
2015-02-10 21:46:08,929 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs*rhs] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/cogroupsplit"]
2015-02-10 21:46:08,930 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs*rhs] parallel execution is enabled: false
2015-02-10 21:46:08,930 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs*rhs] starting jobs: 1
2015-02-10 21:46:08,930 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs*rhs] allocating threads: 1
2015-02-10 21:46:08,931 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lhs*rhs] starting step: (1/1) ...ipesplatform/cogroupsplit
2015-02-10 21:46:08,933 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:08,935 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:08,999 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:09,024 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 21:46:09,073 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1265406646_0003
2015-02-10 21:46:09,103 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity1265406646/.staging/job_local1265406646_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:09,107 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity1265406646/.staging/job_local1265406646_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:09,177 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1265406646_0003/job_local1265406646_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:09,180 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1265406646_0003/job_local1265406646_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:09,180 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:09,181 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lhs*rhs] submitted hadoop job: job_local1265406646_0003
2015-02-10 21:46:09,181 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lhs*rhs] tracking url: http://localhost:8080/
2015-02-10 21:46:09,181 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:09,182 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:09,186 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:09,186 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1265406646_0003_m_000000_0
2015-02-10 21:46:09,189 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:09,191 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/intermediate/part-00000
2015-02-10 21:46:09,191 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@484dd014
2015-02-10 21:46:09,193 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-10 21:46:09,200 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-10 21:46:09,352 INFO mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-10 21:46:09,353 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-10 21:46:09,353 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-10 21:46:09,353 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-10 21:46:09,353 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-10 21:46:09,376 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:09,376 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:09,399 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/intermediate"]
2015-02-10 21:46:09,400 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(lhs*rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num2']]
2015-02-10 21:46:09,406 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:09,406 INFO mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-10 21:46:09,406 INFO mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-10 21:46:09,406 INFO mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 140; bufvoid = 104857600
2015-02-10 21:46:09,406 INFO mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214360(104857440); length = 37/6553600
2015-02-10 21:46:09,420 INFO mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-10 21:46:09,424 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1265406646_0003_m_000000_0 is done. And is in the process of committing
2015-02-10 21:46:09,427 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/intermediate/part-00000:0+20
2015-02-10 21:46:09,427 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1265406646_0003_m_000000_0' done.
2015-02-10 21:46:09,428 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1265406646_0003_m_000000_0
2015-02-10 21:46:09,428 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:09,431 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-10 21:46:09,431 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1265406646_0003_r_000000_0
2015-02-10 21:46:09,438 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:09,442 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@1f561437
2015-02-10 21:46:09,457 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-10 21:46:09,461 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1265406646_0003_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-10 21:46:09,497 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#1 about to shuffle output of map attempt_local1265406646_0003_m_000000_0 decomp: 162 len: 166 to MEMORY
2015-02-10 21:46:09,500 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 162 bytes from map-output for attempt_local1265406646_0003_m_000000_0
2015-02-10 21:46:09,542 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 162, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->162
2015-02-10 21:46:09,543 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-10 21:46:09,545 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:09,545 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-10 21:46:09,555 INFO mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-10 21:46:09,555 INFO mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 152 bytes
2015-02-10 21:46:09,558 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 162 bytes to disk to satisfy reduce memory limit
2015-02-10 21:46:09,558 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 166 bytes from disk
2015-02-10 21:46:09,563 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-10 21:46:09,564 INFO mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-10 21:46:09,564 INFO mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 152 bytes
2015-02-10 21:46:09,565 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:09,567 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-10 21:46:09,567 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-10 21:46:09,582 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(lhs*rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num2']]
2015-02-10 21:46:09,583 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/cogroupsplit"]
2015-02-10 21:46:09,605 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-10 21:46:09,605 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-10 21:46:09,618 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1265406646_0003_r_000000_0 is done. And is in the process of committing
2015-02-10 21:46:09,620 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:09,621 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1265406646_0003_r_000000_0 is allowed to commit now
2015-02-10 21:46:09,622 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1265406646_0003_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/cogroupsplit/_temporary/0/task_local1265406646_0003_r_000000
2015-02-10 21:46:09,623 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-10 21:46:09,624 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1265406646_0003_r_000000_0' done.
2015-02-10 21:46:09,624 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1265406646_0003_r_000000_0
2015-02-10 21:46:09,624 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-10 21:46:09,650 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/cogroupsplit/_temporary
2015-02-10 21:46:09,693 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:09,739 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:09,741 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/intermediate
2015-02-10 21:46:09,742 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/cogroupsplit
2015-02-10 21:46:09,773 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 21:46:09,773 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-10 21:46:09,789 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:09,794 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:09,795 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 21:46:09,808 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 21:46:09,808 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 21:46:09,809 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/none-unknown"]
2015-02-10 21:46:09,809 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 21:46:09,809 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 21:46:09,810 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 21:46:09,810 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...ipesplatform/none-unknown
2015-02-10 21:46:09,812 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:09,814 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:09,865 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:09,892 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 21:46:09,913 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local730191465_0004
2015-02-10 21:46:09,941 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity730191465/.staging/job_local730191465_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:09,944 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity730191465/.staging/job_local730191465_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:10,009 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local730191465_0004/job_local730191465_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:10,012 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local730191465_0004/job_local730191465_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:10,013 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:10,013 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local730191465_0004
2015-02-10 21:46:10,014 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 21:46:10,014 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:10,015 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:10,019 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:10,019 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local730191465_0004_m_000000_0
2015-02-10 21:46:10,022 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:10,024 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt
2015-02-10 21:46:10,024 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@6153e0c0
2015-02-10 21:46:10,026 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-10 21:46:10,026 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-10 21:46:10,178 INFO mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-10 21:46:10,178 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-10 21:46:10,178 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-10 21:46:10,178 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-10 21:46:10,179 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-10 21:46:10,182 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:10,182 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:10,194 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 21:46:10,194 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{?}:NONE]]
2015-02-10 21:46:10,197 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:10,198 INFO mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-10 21:46:10,198 INFO mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-10 21:46:10,198 INFO mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 135; bufvoid = 104857600
2015-02-10 21:46:10,198 INFO mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214380(104857520); length = 17/6553600
2015-02-10 21:46:10,202 INFO mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-10 21:46:10,205 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local730191465_0004_m_000000_0 is done. And is in the process of committing
2015-02-10 21:46:10,208 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt:0+30
2015-02-10 21:46:10,208 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local730191465_0004_m_000000_0' done.
2015-02-10 21:46:10,208 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local730191465_0004_m_000000_0
2015-02-10 21:46:10,208 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:10,209 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-10 21:46:10,209 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local730191465_0004_r_000000_0
2015-02-10 21:46:10,212 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:10,212 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@6128453c
2015-02-10 21:46:10,213 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-10 21:46:10,214 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local730191465_0004_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-10 21:46:10,217 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#2 about to shuffle output of map attempt_local730191465_0004_m_000000_0 decomp: 147 len: 151 to MEMORY
2015-02-10 21:46:10,218 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 147 bytes from map-output for attempt_local730191465_0004_m_000000_0
2015-02-10 21:46:10,219 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 147, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->147
2015-02-10 21:46:10,220 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-10 21:46:10,221 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:10,221 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-10 21:46:10,224 INFO mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-10 21:46:10,224 INFO mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 137 bytes
2015-02-10 21:46:10,226 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 147 bytes to disk to satisfy reduce memory limit
2015-02-10 21:46:10,227 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 151 bytes from disk
2015-02-10 21:46:10,227 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-10 21:46:10,227 INFO mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-10 21:46:10,227 INFO mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 137 bytes
2015-02-10 21:46:10,228 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:10,229 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-10 21:46:10,229 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-10 21:46:10,239 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{?}:NONE]]
2015-02-10 21:46:10,240 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/none-unknown"]
2015-02-10 21:46:10,256 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local730191465_0004_r_000000_0 is done. And is in the process of committing
2015-02-10 21:46:10,258 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:10,258 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local730191465_0004_r_000000_0 is allowed to commit now
2015-02-10 21:46:10,259 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local730191465_0004_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/none-unknown/_temporary/0/task_local730191465_0004_r_000000
2015-02-10 21:46:10,260 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-10 21:46:10,261 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local730191465_0004_r_000000_0' done.
2015-02-10 21:46:10,261 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local730191465_0004_r_000000_0
2015-02-10 21:46:10,261 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-10 21:46:10,292 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/none-unknown/_temporary
2015-02-10 21:46:10,326 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:10,328 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/none-unknown
2015-02-10 21:46:10,352 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 21:46:10,353 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-10 21:46:10,362 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:10,368 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:10,369 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 21:46:10,387 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 21:46:10,387 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2015-02-10 21:46:10,387 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/oomepre"]
2015-02-10 21:46:10,388 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 21:46:10,388 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 21:46:10,388 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 21:46:10,389 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...sionpipesplatform/oomepre
2015-02-10 21:46:10,391 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:10,393 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:10,424 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:10,447 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 21:46:10,480 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local324297978_0005
2015-02-10 21:46:10,523 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity324297978/.staging/job_local324297978_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:10,525 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity324297978/.staging/job_local324297978_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:10,580 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local324297978_0005/job_local324297978_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:10,581 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local324297978_0005/job_local324297978_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:10,581 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:10,582 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local324297978_0005
2015-02-10 21:46:10,582 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:10,582 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 21:46:10,582 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:10,586 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:10,587 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local324297978_0005_m_000000_0
2015-02-10 21:46:10,590 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:10,591 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/apache.10.txt
2015-02-10 21:46:10,592 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@28fe04c6
2015-02-10 21:46:10,593 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 21:46:10,602 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:10,602 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:10,611 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2015-02-10 21:46:10,611 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/oomepre"]
2015-02-10 21:46:10,614 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught OutOfMemoryException, will not trap, rethrowing
java.lang.OutOfMemoryError: fake error
at cascading.RegressionPipesPlatformTest$1.throwIntentionalException(RegressionPipesPlatformTest.java:593)
at cascading.TestFunction.operate(TestFunction.java:74)
at cascading.flow.stream.FunctionEachStage.receive(FunctionEachStage.java:99)
at cascading.flow.stream.FunctionEachStage.receive(FunctionEachStage.java:39)
at cascading.flow.stream.SourceStage.map(SourceStage.java:102)
at cascading.flow.stream.SourceStage.run(SourceStage.java:58)
at cascading.flow.hadoop.FlowMapper.run(FlowMapper.java:130)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:430)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:342)
at org.apache.hadoop.mapred.LocalJobRunner$Job$MapTaskRunnable.run(LocalJobRunner.java:243)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
at java.lang.Thread.run(Thread.java:662)
2015-02-10 21:46:10,617 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:10,618 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local324297978_0005
java.lang.Exception: java.lang.OutOfMemoryError: fake error
at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:522)
Caused by: java.lang.OutOfMemoryError: fake error
at cascading.RegressionPipesPlatformTest$1.throwIntentionalException(RegressionPipesPlatformTest.java:593)
at cascading.TestFunction.operate(TestFunction.java:74)
at cascading.flow.stream.FunctionEachStage.receive(FunctionEachStage.java:99)
at cascading.flow.stream.FunctionEachStage.receive(FunctionEachStage.java:39)
at cascading.flow.stream.SourceStage.map(SourceStage.java:102)
at cascading.flow.stream.SourceStage.run(SourceStage.java:58)
at cascading.flow.hadoop.FlowMapper.run(FlowMapper.java:130)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:430)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:342)
at org.apache.hadoop.mapred.LocalJobRunner$Job$MapTaskRunnable.run(LocalJobRunner.java:243)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
at java.lang.Thread.run(Thread.java:662)
2015-02-10 21:46:10,624 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local324297978_0005 state at FAILED
2015-02-10 21:46:10,625 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2015-02-10 21:46:10,626 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2015-02-10 21:46:10,626 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2015-02-10 21:46:10,627 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopping all jobs
2015-02-10 21:46:10,628 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...sionpipesplatform/oomepre
2015-02-10 21:46:10,628 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopped all jobs
2015-02-10 21:46:10,629 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] shutting down job executor
2015-02-10 21:46:10,630 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] shutdown complete
2015-02-10 21:46:10,631 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/oomepre/_temporary
exception = cascading.flow.FlowException: local step failed
2015-02-10 21:46:10,633 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/oomepre
2015-02-10 21:46:10,654 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 21:46:10,654 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-10 21:46:10,662 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:10,666 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:10,667 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 21:46:10,673 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 21:46:10,673 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 21:46:10,676 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/copy"]
2015-02-10 21:46:10,676 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 21:46:10,677 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 21:46:10,677 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 21:46:10,678 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...ressionpipesplatform/copy
2015-02-10 21:46:10,680 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:10,682 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:10,711 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:10,732 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 21:46:10,749 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1823304606_0006
2015-02-10 21:46:10,768 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity1823304606/.staging/job_local1823304606_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:10,769 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity1823304606/.staging/job_local1823304606_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:10,822 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1823304606_0006/job_local1823304606_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:10,823 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1823304606_0006/job_local1823304606_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:10,824 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:10,826 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:10,826 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:10,826 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1823304606_0006
2015-02-10 21:46:10,827 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 21:46:10,830 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:10,830 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1823304606_0006_m_000000_0
2015-02-10 21:46:10,833 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:10,834 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt
2015-02-10 21:46:10,835 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@22652552
2015-02-10 21:46:10,837 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 21:46:10,846 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:10,846 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:10,852 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 21:46:10,853 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/copy"]
2015-02-10 21:46:10,856 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:10,857 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1823304606_0006_m_000000_0 is done. And is in the process of committing
2015-02-10 21:46:10,859 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:10,859 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1823304606_0006_m_000000_0 is allowed to commit now
2015-02-10 21:46:10,861 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1823304606_0006_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/copy/_temporary/0/task_local1823304606_0006_m_000000
2015-02-10 21:46:10,863 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt:0+30
2015-02-10 21:46:10,863 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1823304606_0006_m_000000_0' done.
2015-02-10 21:46:10,864 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1823304606_0006_m_000000_0
2015-02-10 21:46:10,864 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:10,884 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/copy/_temporary
2015-02-10 21:46:10,918 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:10,921 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/copy
2015-02-10 21:46:10,953 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 21:46:10,954 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-10 21:46:10,969 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:10,973 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:10,975 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 21:46:10,986 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 21:46:10,986 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 21:46:10,987 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/unknown-replace"]
2015-02-10 21:46:10,987 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 21:46:10,987 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 21:46:10,987 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 21:46:10,988 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...splatform/unknown-replace
2015-02-10 21:46:10,989 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:10,990 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:11,019 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:11,040 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 21:46:11,064 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1729892758_0007
2015-02-10 21:46:11,089 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity1729892758/.staging/job_local1729892758_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:11,091 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity1729892758/.staging/job_local1729892758_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:11,161 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1729892758_0007/job_local1729892758_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:11,164 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1729892758_0007/job_local1729892758_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:11,165 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:11,165 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:11,166 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:11,165 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1729892758_0007
2015-02-10 21:46:11,167 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 21:46:11,170 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:11,170 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1729892758_0007_m_000000_0
2015-02-10 21:46:11,172 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:11,176 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt
2015-02-10 21:46:11,176 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@18247418
2015-02-10 21:46:11,178 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 21:46:11,188 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:11,189 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:11,199 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 21:46:11,199 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/unknown-replace"]
2015-02-10 21:46:11,205 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:11,206 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1729892758_0007_m_000000_0 is done. And is in the process of committing
2015-02-10 21:46:11,207 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:11,208 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1729892758_0007_m_000000_0 is allowed to commit now
2015-02-10 21:46:11,209 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1729892758_0007_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/unknown-replace/_temporary/0/task_local1729892758_0007_m_000000
2015-02-10 21:46:11,210 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt:0+30
2015-02-10 21:46:11,210 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1729892758_0007_m_000000_0' done.
2015-02-10 21:46:11,211 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1729892758_0007_m_000000_0
2015-02-10 21:46:11,211 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:11,234 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/unknown-replace/_temporary
2015-02-10 21:46:11,279 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:11,318 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:11,320 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/unknown-replace
2015-02-10 21:46:11,346 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 21:46:11,346 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-10 21:46:11,357 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:11,360 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:11,361 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 21:46:11,370 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 21:46:11,371 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lhs.txt"]
2015-02-10 21:46:11,371 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicand"]
2015-02-10 21:46:11,371 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 21:46:11,371 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 21:46:11,371 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 21:46:11,372 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...egression/complexlogicand
2015-02-10 21:46:11,373 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:11,374 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:11,402 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:11,422 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 21:46:11,440 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local55372503_0008
2015-02-10 21:46:11,459 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity55372503/.staging/job_local55372503_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:11,461 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity55372503/.staging/job_local55372503_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:11,518 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local55372503_0008/job_local55372503_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:11,519 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local55372503_0008/job_local55372503_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:11,520 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:11,521 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:11,521 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:11,521 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local55372503_0008
2015-02-10 21:46:11,521 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 21:46:11,524 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:11,524 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local55372503_0008_m_000000_0
2015-02-10 21:46:11,527 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:11,529 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lhs.txt
2015-02-10 21:46:11,530 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@7c1c8c58
2015-02-10 21:46:11,532 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 21:46:11,541 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:11,542 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:11,551 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lhs.txt"]
2015-02-10 21:46:11,552 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicand"]
2015-02-10 21:46:11,555 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:11,556 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local55372503_0008_m_000000_0 is done. And is in the process of committing
2015-02-10 21:46:11,557 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:11,558 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local55372503_0008_m_000000_0 is allowed to commit now
2015-02-10 21:46:11,559 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local55372503_0008_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicand/_temporary/0/task_local55372503_0008_m_000000
2015-02-10 21:46:11,560 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lhs.txt:0+52
2015-02-10 21:46:11,560 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local55372503_0008_m_000000_0' done.
2015-02-10 21:46:11,561 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local55372503_0008_m_000000_0
2015-02-10 21:46:11,561 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:11,578 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicand/_temporary
2015-02-10 21:46:11,611 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:11,613 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/regression/complexlogicand
2015-02-10 21:46:11,641 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 21:46:11,642 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-10 21:46:11,655 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:11,659 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:11,660 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 21:46:11,670 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 21:46:11,671 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lhs.txt"]
2015-02-10 21:46:11,671 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicxor"]
2015-02-10 21:46:11,671 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 21:46:11,671 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 21:46:11,671 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 21:46:11,673 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...egression/complexlogicxor
2015-02-10 21:46:11,674 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:11,675 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:11,707 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:11,729 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 21:46:11,751 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1881713251_0009
2015-02-10 21:46:11,774 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity1881713251/.staging/job_local1881713251_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:11,775 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity1881713251/.staging/job_local1881713251_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:11,835 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1881713251_0009/job_local1881713251_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:11,836 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1881713251_0009/job_local1881713251_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:11,837 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:11,838 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1881713251_0009
2015-02-10 21:46:11,838 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:11,838 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:11,838 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 21:46:11,842 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:11,842 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1881713251_0009_m_000000_0
2015-02-10 21:46:11,845 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:11,847 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lhs.txt
2015-02-10 21:46:11,847 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@17046822
2015-02-10 21:46:11,849 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 21:46:11,859 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:11,860 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:11,869 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lhs.txt"]
2015-02-10 21:46:11,870 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicxor"]
2015-02-10 21:46:11,874 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:11,875 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1881713251_0009_m_000000_0 is done. And is in the process of committing
2015-02-10 21:46:11,878 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:11,879 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1881713251_0009_m_000000_0 is allowed to commit now
2015-02-10 21:46:11,880 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1881713251_0009_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicxor/_temporary/0/task_local1881713251_0009_m_000000
2015-02-10 21:46:11,881 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lhs.txt:0+52
2015-02-10 21:46:11,882 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1881713251_0009_m_000000_0' done.
2015-02-10 21:46:11,882 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1881713251_0009_m_000000_0
2015-02-10 21:46:11,882 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:11,905 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicxor/_temporary
2015-02-10 21:46:11,941 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:11,944 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/regression/complexlogicxor
2015-02-10 21:46:11,970 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 21:46:11,971 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-10 21:46:12,001 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:12,007 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:12,008 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 21:46:12,019 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lower*upper] starting
2015-02-10 21:46:12,019 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/upper.txt"]
2015-02-10 21:46:12,019 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower.txt"]
2015-02-10 21:46:12,020 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lower*upper] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/oomepost"]
2015-02-10 21:46:12,020 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lower*upper] parallel execution is enabled: false
2015-02-10 21:46:12,020 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lower*upper] starting jobs: 1
2015-02-10 21:46:12,020 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lower*upper] allocating threads: 1
2015-02-10 21:46:12,021 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lower*upper] starting step: (1/1) ...ionpipesplatform/oomepost
2015-02-10 21:46:12,021 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:12,022 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:12,051 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:12,053 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:12,074 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:2
2015-02-10 21:46:12,092 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local595796634_0010
2015-02-10 21:46:12,115 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity595796634/.staging/job_local595796634_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:12,117 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity595796634/.staging/job_local595796634_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:12,175 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local595796634_0010/job_local595796634_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:12,176 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local595796634_0010/job_local595796634_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:12,177 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:12,177 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lower*upper] submitted hadoop job: job_local595796634_0010
2015-02-10 21:46:12,178 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lower*upper] tracking url: http://localhost:8080/
2015-02-10 21:46:12,178 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:12,178 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:12,183 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:12,183 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local595796634_0010_m_000000_0
2015-02-10 21:46:12,186 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:12,188 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower.txt
2015-02-10 21:46:12,188 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@4cd98b00
2015-02-10 21:46:12,190 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-10 21:46:12,191 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-10 21:46:12,344 INFO mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-10 21:46:12,344 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-10 21:46:12,344 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-10 21:46:12,345 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-10 21:46:12,345 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-10 21:46:12,347 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:12,347 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:12,358 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower.txt"]
2015-02-10 21:46:12,358 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2015-02-10 21:46:12,361 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:12,361 INFO mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-10 21:46:12,361 INFO mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-10 21:46:12,361 INFO mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 85; bufvoid = 104857600
2015-02-10 21:46:12,362 INFO mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214380(104857520); length = 17/6553600
2015-02-10 21:46:12,365 INFO mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-10 21:46:12,367 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local595796634_0010_m_000000_0 is done. And is in the process of committing
2015-02-10 21:46:12,370 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower.txt:0+19
2015-02-10 21:46:12,370 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local595796634_0010_m_000000_0' done.
2015-02-10 21:46:12,370 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local595796634_0010_m_000000_0
2015-02-10 21:46:12,370 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local595796634_0010_m_000001_0
2015-02-10 21:46:12,372 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:12,373 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/upper.txt
2015-02-10 21:46:12,374 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@77b4ee5e
2015-02-10 21:46:12,375 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-10 21:46:12,375 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-10 21:46:12,519 INFO mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-10 21:46:12,519 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-10 21:46:12,519 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-10 21:46:12,519 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-10 21:46:12,519 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-10 21:46:12,521 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:12,522 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:12,533 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/upper.txt"]
2015-02-10 21:46:12,533 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2015-02-10 21:46:12,536 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:12,536 INFO mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-10 21:46:12,536 INFO mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-10 21:46:12,536 INFO mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 85; bufvoid = 104857600
2015-02-10 21:46:12,536 INFO mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214380(104857520); length = 17/6553600
2015-02-10 21:46:12,540 INFO mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-10 21:46:12,542 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local595796634_0010_m_000001_0 is done. And is in the process of committing
2015-02-10 21:46:12,544 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/upper.txt:0+19
2015-02-10 21:46:12,545 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local595796634_0010_m_000001_0' done.
2015-02-10 21:46:12,545 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local595796634_0010_m_000001_0
2015-02-10 21:46:12,545 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:12,546 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-10 21:46:12,546 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local595796634_0010_r_000000_0
2015-02-10 21:46:12,548 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:12,548 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@4bea71d4
2015-02-10 21:46:12,550 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-10 21:46:12,551 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local595796634_0010_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-10 21:46:12,554 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#3 about to shuffle output of map attempt_local595796634_0010_m_000000_0 decomp: 97 len: 101 to MEMORY
2015-02-10 21:46:12,554 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 97 bytes from map-output for attempt_local595796634_0010_m_000000_0
2015-02-10 21:46:12,555 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 97, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->97
2015-02-10 21:46:12,557 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#3 about to shuffle output of map attempt_local595796634_0010_m_000001_0 decomp: 97 len: 101 to MEMORY
2015-02-10 21:46:12,558 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 97 bytes from map-output for attempt_local595796634_0010_m_000001_0
2015-02-10 21:46:12,558 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 97, inMemoryMapOutputs.size() -> 2, commitMemory -> 97, usedMemory ->194
2015-02-10 21:46:12,559 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-10 21:46:12,560 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 2 / 2 copied.
2015-02-10 21:46:12,561 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 2 in-memory map-outputs and 0 on-disk map-outputs
2015-02-10 21:46:12,563 INFO mapred.Merger (Merger.java:merge(591)) - Merging 2 sorted segments
2015-02-10 21:46:12,564 INFO mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 2 segments left of total size: 174 bytes
2015-02-10 21:46:12,567 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 2 segments, 194 bytes to disk to satisfy reduce memory limit
2015-02-10 21:46:12,567 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 196 bytes from disk
2015-02-10 21:46:12,568 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-10 21:46:12,568 INFO mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-10 21:46:12,569 INFO mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 182 bytes
2015-02-10 21:46:12,570 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 2 / 2 copied.
2015-02-10 21:46:12,571 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-10 21:46:12,571 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-10 21:46:12,581 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2015-02-10 21:46:12,581 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/oomepost"]
2015-02-10 21:46:12,591 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-10 21:46:12,592 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-10 21:46:12,593 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught OutOfMemoryException, will not trap, rethrowing
java.lang.OutOfMemoryError: fake error
at cascading.RegressionPipesPlatformTest$2.throwIntentionalException(RegressionPipesPlatformTest.java:643)
at cascading.TestFunction.operate(TestFunction.java:74)
at cascading.flow.stream.FunctionEachStage.receive(FunctionEachStage.java:99)
at cascading.flow.stream.FunctionEachStage.receive(FunctionEachStage.java:39)
at cascading.flow.stream.OpenDuct.receive(OpenDuct.java:45)
at cascading.flow.stream.OpenDuct.receive(OpenDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
at java.lang.Thread.run(Thread.java:662)
2015-02-10 21:46:12,594 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-10 21:46:12,597 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local595796634_0010
java.lang.Exception: java.lang.OutOfMemoryError: fake error
at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:529)
Caused by: java.lang.OutOfMemoryError: fake error
at cascading.RegressionPipesPlatformTest$2.throwIntentionalException(RegressionPipesPlatformTest.java:643)
at cascading.TestFunction.operate(TestFunction.java:74)
at cascading.flow.stream.FunctionEachStage.receive(FunctionEachStage.java:99)
at cascading.flow.stream.FunctionEachStage.receive(FunctionEachStage.java:39)
at cascading.flow.stream.OpenDuct.receive(OpenDuct.java:45)
at cascading.flow.stream.OpenDuct.receive(OpenDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
at java.lang.Thread.run(Thread.java:662)
2015-02-10 21:46:12,605 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [lower*upper] hadoop job job_local595796634_0010 state at FAILED
2015-02-10 21:46:12,605 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [lower*upper] failure info: NA
2015-02-10 21:46:12,605 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [lower*upper] task completion events identify failed tasks
2015-02-10 21:46:12,605 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [lower*upper] task completion events count: 0
2015-02-10 21:46:12,621 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lower*upper] stopping all jobs
2015-02-10 21:46:12,622 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lower*upper] stopping: (1/1) ...ionpipesplatform/oomepost
2015-02-10 21:46:12,623 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lower*upper] stopped all jobs
2015-02-10 21:46:12,623 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/oomepost/_temporary
exception = cascading.flow.FlowException: local step failed
2015-02-10 21:46:12,625 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/oomepost
2015-02-10 21:46:12,646 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 21:46:12,646 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-10 21:46:12,655 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:12,658 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:12,658 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 21:46:12,665 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 21:46:12,666 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2015-02-10 21:46:12,666 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/lasteachmodified"]
2015-02-10 21:46:12,666 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 21:46:12,666 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 21:46:12,666 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 21:46:12,667 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...platform/lasteachmodified
2015-02-10 21:46:12,668 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:12,669 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:12,695 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:12,715 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 21:46:12,732 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1176356164_0011
2015-02-10 21:46:12,752 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity1176356164/.staging/job_local1176356164_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:12,753 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity1176356164/.staging/job_local1176356164_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:12,809 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1176356164_0011/job_local1176356164_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:12,810 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1176356164_0011/job_local1176356164_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:12,811 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:12,811 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1176356164_0011
2015-02-10 21:46:12,812 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:12,812 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 21:46:12,812 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:12,815 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:12,816 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1176356164_0011_m_000000_0
2015-02-10 21:46:12,818 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:12,821 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/apache.10.txt
2015-02-10 21:46:12,821 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@4839880a
2015-02-10 21:46:12,822 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-10 21:46:12,823 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-10 21:46:12,981 INFO mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-10 21:46:12,982 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-10 21:46:12,982 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-10 21:46:12,982 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-10 21:46:12,982 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-10 21:46:12,984 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:12,984 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:12,991 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/apache.10.txt"]
2015-02-10 21:46:12,991 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'insert']]
2015-02-10 21:46:12,995 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:12,995 INFO mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-10 21:46:12,995 INFO mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-10 21:46:12,995 INFO mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 160; bufvoid = 104857600
2015-02-10 21:46:12,995 INFO mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214360(104857440); length = 37/6553600
2015-02-10 21:46:12,999 INFO mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-10 21:46:13,001 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1176356164_0011_m_000000_0 is done. And is in the process of committing
2015-02-10 21:46:13,003 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/apache.10.txt:0+1449
2015-02-10 21:46:13,003 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1176356164_0011_m_000000_0' done.
2015-02-10 21:46:13,004 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1176356164_0011_m_000000_0
2015-02-10 21:46:13,004 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:13,004 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-10 21:46:13,005 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1176356164_0011_r_000000_0
2015-02-10 21:46:13,007 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:13,007 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@7d628303
2015-02-10 21:46:13,008 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-10 21:46:13,009 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1176356164_0011_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-10 21:46:13,011 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#4 about to shuffle output of map attempt_local1176356164_0011_m_000000_0 decomp: 182 len: 186 to MEMORY
2015-02-10 21:46:13,011 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 182 bytes from map-output for attempt_local1176356164_0011_m_000000_0
2015-02-10 21:46:13,012 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 182, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->182
2015-02-10 21:46:13,012 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-10 21:46:13,013 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:13,014 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-10 21:46:13,016 INFO mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-10 21:46:13,016 INFO mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 166 bytes
2015-02-10 21:46:13,018 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 182 bytes to disk to satisfy reduce memory limit
2015-02-10 21:46:13,018 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 186 bytes from disk
2015-02-10 21:46:13,018 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-10 21:46:13,018 INFO mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-10 21:46:13,019 INFO mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 166 bytes
2015-02-10 21:46:13,020 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:13,020 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-10 21:46:13,020 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-10 21:46:13,027 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'insert']]
2015-02-10 21:46:13,027 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/lasteachmodified"]
2015-02-10 21:46:13,038 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1176356164_0011_r_000000_0 is done. And is in the process of committing
2015-02-10 21:46:13,040 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:13,040 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1176356164_0011_r_000000_0 is allowed to commit now
2015-02-10 21:46:13,041 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1176356164_0011_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/lasteachmodified/_temporary/0/task_local1176356164_0011_r_000000
2015-02-10 21:46:13,042 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-10 21:46:13,042 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1176356164_0011_r_000000_0' done.
2015-02-10 21:46:13,043 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1176356164_0011_r_000000_0
2015-02-10 21:46:13,043 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-10 21:46:13,064 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/lasteachmodified/_temporary
2015-02-10 21:46:13,096 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:13,098 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/lasteachmodified
2015-02-10 21:46:13,125 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 21:46:13,125 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-10 21:46:13,136 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:13,138 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:13,139 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 21:46:13,145 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 21:46:13,146 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 21:46:13,146 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/unknown"]
2015-02-10 21:46:13,146 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 21:46:13,146 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 21:46:13,146 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 21:46:13,147 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...sionpipesplatform/unknown
2015-02-10 21:46:13,148 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:13,150 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:13,488 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:13,509 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 21:46:13,525 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local900745614_0012
2015-02-10 21:46:13,545 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity900745614/.staging/job_local900745614_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:13,547 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity900745614/.staging/job_local900745614_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:13,596 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local900745614_0012/job_local900745614_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:13,597 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local900745614_0012/job_local900745614_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:13,597 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:13,598 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local900745614_0012
2015-02-10 21:46:13,598 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 21:46:13,599 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:13,599 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:13,602 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:13,602 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local900745614_0012_m_000000_0
2015-02-10 21:46:13,604 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:13,606 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt
2015-02-10 21:46:13,606 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@76ad962c
2015-02-10 21:46:13,607 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 21:46:13,615 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:13,615 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:13,623 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 21:46:13,623 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/unknown"]
2015-02-10 21:46:13,627 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:13,627 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local900745614_0012_m_000000_0 is done. And is in the process of committing
2015-02-10 21:46:13,628 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:13,629 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local900745614_0012_m_000000_0 is allowed to commit now
2015-02-10 21:46:13,629 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local900745614_0012_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/unknown/_temporary/0/task_local900745614_0012_m_000000
2015-02-10 21:46:13,631 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt:0+30
2015-02-10 21:46:13,631 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local900745614_0012_m_000000_0' done.
2015-02-10 21:46:13,631 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local900745614_0012_m_000000_0
2015-02-10 21:46:13,631 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:13,653 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/unknown/_temporary
2015-02-10 21:46:13,683 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:13,685 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/unknown
2015-02-10 21:46:13,708 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 21:46:13,709 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-10 21:46:13,717 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:13,720 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:13,720 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 21:46:13,729 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 21:46:13,729 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/critics.txt"]
2015-02-10 21:46:13,729 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/varwidth"]
2015-02-10 21:46:13,729 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 21:46:13,729 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 21:46:13,730 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 21:46:13,730 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...ionpipesplatform/varwidth
2015-02-10 21:46:13,731 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:13,732 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:13,757 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:13,776 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 21:46:13,791 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1036660394_0013
2015-02-10 21:46:13,809 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity1036660394/.staging/job_local1036660394_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:13,810 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity1036660394/.staging/job_local1036660394_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:13,858 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1036660394_0013/job_local1036660394_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:13,859 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1036660394_0013/job_local1036660394_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:13,860 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:13,860 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1036660394_0013
2015-02-10 21:46:13,860 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 21:46:13,861 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:13,861 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:13,864 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:13,864 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1036660394_0013_m_000000_0
2015-02-10 21:46:13,866 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:13,868 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/critics.txt
2015-02-10 21:46:13,868 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@2b2143d8
2015-02-10 21:46:13,870 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 21:46:13,930 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:13,930 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:13,938 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/critics.txt"]
2015-02-10 21:46:13,938 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/varwidth"]
2015-02-10 21:46:13,943 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:13,944 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1036660394_0013_m_000000_0 is done. And is in the process of committing
2015-02-10 21:46:13,946 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:13,946 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1036660394_0013_m_000000_0 is allowed to commit now
2015-02-10 21:46:13,947 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1036660394_0013_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/varwidth/_temporary/0/task_local1036660394_0013_m_000000
2015-02-10 21:46:13,949 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/critics.txt:0+828
2015-02-10 21:46:13,949 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1036660394_0013_m_000000_0' done.
2015-02-10 21:46:13,949 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1036660394_0013_m_000000_0
2015-02-10 21:46:13,950 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:13,966 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/varwidth/_temporary
2015-02-10 21:46:13,999 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:14,000 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/varwidth
2015-02-10 21:46:14,429 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 21:46:14,429 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-10 21:46:14,949 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:14,952 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:14,952 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 21:46:15,081 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [pipeline] starting
2015-02-10 21:46:15,081 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [pipeline] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/apache.200.txt"]
2015-02-10 21:46:15,081 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [pipeline] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/deeppipline"]
2015-02-10 21:46:15,082 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [pipeline] parallel execution is enabled: false
2015-02-10 21:46:15,082 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [pipeline] starting jobs: 1
2015-02-10 21:46:15,082 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [pipeline] allocating threads: 1
2015-02-10 21:46:15,083 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pipeline] starting step: (1/1) ...pipesplatform/deeppipline
2015-02-10 21:46:15,083 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:15,084 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:15,110 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:15,130 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 21:46:15,146 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local779658320_0014
2015-02-10 21:46:15,165 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity779658320/.staging/job_local779658320_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:15,167 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity779658320/.staging/job_local779658320_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:15,223 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local779658320_0014/job_local779658320_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:15,224 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local779658320_0014/job_local779658320_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:15,225 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:15,225 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pipeline] submitted hadoop job: job_local779658320_0014
2015-02-10 21:46:15,225 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:15,225 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pipeline] tracking url: http://localhost:8080/
2015-02-10 21:46:15,225 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:15,229 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:15,229 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local779658320_0014_m_000000_0
2015-02-10 21:46:15,231 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:15,233 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/apache.200.txt
2015-02-10 21:46:15,233 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@3fe8032c
2015-02-10 21:46:15,235 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-10 21:46:15,235 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-10 21:46:15,308 INFO mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-10 21:46:15,309 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-10 21:46:15,309 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-10 21:46:15,309 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-10 21:46:15,310 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-10 21:46:15,311 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:15,312 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:15,577 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/apache.200.txt"]
2015-02-10 21:46:15,578 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(pipeline)[by:[{1}:'hash']]
2015-02-10 21:46:15,857 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:15,858 INFO mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-10 21:46:15,858 INFO mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-10 21:46:15,858 INFO mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 35385; bufvoid = 104857600
2015-02-10 21:46:15,859 INFO mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26213600(104854400); length = 797/6553600
2015-02-10 21:46:15,888 INFO mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-10 21:46:15,891 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local779658320_0014_m_000000_0 is done. And is in the process of committing
2015-02-10 21:46:15,893 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/apache.200.txt:0+32599
2015-02-10 21:46:15,894 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local779658320_0014_m_000000_0' done.
2015-02-10 21:46:15,894 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local779658320_0014_m_000000_0
2015-02-10 21:46:15,894 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:15,895 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-10 21:46:15,895 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local779658320_0014_r_000000_0
2015-02-10 21:46:15,898 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:15,898 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@23d7b6d4
2015-02-10 21:46:15,899 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-10 21:46:15,900 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local779658320_0014_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-10 21:46:15,903 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#5 about to shuffle output of map attempt_local779658320_0014_m_000000_0 decomp: 35984 len: 35988 to MEMORY
2015-02-10 21:46:15,904 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 35984 bytes from map-output for attempt_local779658320_0014_m_000000_0
2015-02-10 21:46:15,904 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 35984, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->35984
2015-02-10 21:46:15,905 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-10 21:46:15,906 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:15,907 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-10 21:46:15,909 INFO mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-10 21:46:15,910 INFO mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 35975 bytes
2015-02-10 21:46:15,915 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 35984 bytes to disk to satisfy reduce memory limit
2015-02-10 21:46:15,916 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 35988 bytes from disk
2015-02-10 21:46:15,916 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-10 21:46:15,916 INFO mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-10 21:46:15,917 INFO mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 35975 bytes
2015-02-10 21:46:15,918 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:15,919 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-10 21:46:15,926 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-10 21:46:16,048 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(pipeline)[by:[{1}:'hash']]
2015-02-10 21:46:16,048 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/deeppipline"]
2015-02-10 21:46:16,580 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local779658320_0014_r_000000_0 is done. And is in the process of committing
2015-02-10 21:46:16,582 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:16,582 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local779658320_0014_r_000000_0 is allowed to commit now
2015-02-10 21:46:16,583 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local779658320_0014_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/deeppipline/_temporary/0/task_local779658320_0014_r_000000
2015-02-10 21:46:16,584 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-10 21:46:16,585 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local779658320_0014_r_000000_0' done.
2015-02-10 21:46:16,585 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local779658320_0014_r_000000_0
2015-02-10 21:46:16,585 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-10 21:46:16,589 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/apache.10.txt:0+1449 > map
2015-02-10 21:46:16,610 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/deeppipline/_temporary
2015-02-10 21:46:16,611 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/deeppipline
2015-02-10 21:46:16,630 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 21:46:16,630 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-10 21:46:16,635 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:16,637 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:16,638 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 21:46:16,642 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] starting
2015-02-10 21:46:16,643 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower.txt"]
2015-02-10 21:46:16,644 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/splitintermediate"]
2015-02-10 21:46:16,644 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] parallel execution is enabled: false
2015-02-10 21:46:16,645 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] starting jobs: 1
2015-02-10 21:46:16,646 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] allocating threads: 1
2015-02-10 21:46:16,648 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [split] starting step: (1/1) ...latform/splitintermediate
2015-02-10 21:46:16,648 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:16,650 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:16,674 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:16,694 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 21:46:16,710 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1588661052_0015
2015-02-10 21:46:16,728 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity1588661052/.staging/job_local1588661052_0015/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:16,729 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity1588661052/.staging/job_local1588661052_0015/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:16,777 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1588661052_0015/job_local1588661052_0015.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:16,778 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1588661052_0015/job_local1588661052_0015.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:16,779 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:16,780 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:16,780 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:16,780 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [split] submitted hadoop job: job_local1588661052_0015
2015-02-10 21:46:16,780 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [split] tracking url: http://localhost:8080/
2015-02-10 21:46:16,783 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:16,783 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1588661052_0015_m_000000_0
2015-02-10 21:46:16,784 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:16,787 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower.txt
2015-02-10 21:46:16,787 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@1c6cdb70
2015-02-10 21:46:16,788 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 21:46:16,797 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:16,797 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:16,801 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower.txt"]
2015-02-10 21:46:16,801 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/splitintermediate"]
2015-02-10 21:46:16,804 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:16,804 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1588661052_0015_m_000000_0 is done. And is in the process of committing
2015-02-10 21:46:16,806 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:16,806 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1588661052_0015_m_000000_0 is allowed to commit now
2015-02-10 21:46:16,807 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1588661052_0015_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/splitintermediate/_temporary/0/task_local1588661052_0015_m_000000
2015-02-10 21:46:16,808 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower.txt:0+19
2015-02-10 21:46:16,808 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1588661052_0015_m_000000_0' done.
2015-02-10 21:46:16,808 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1588661052_0015_m_000000_0
2015-02-10 21:46:16,808 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:16,828 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/splitintermediate/_temporary
2015-02-10 21:46:16,846 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 21:46:16,846 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-10 21:46:16,854 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:16,856 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:16,857 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 21:46:16,861 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs+rhs] starting
2015-02-10 21:46:16,861 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs+rhs] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/splitintermediate"]
2015-02-10 21:46:16,861 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs+rhs] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/groupbysplit"]
2015-02-10 21:46:16,862 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs+rhs] parallel execution is enabled: false
2015-02-10 21:46:16,862 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs+rhs] starting jobs: 1
2015-02-10 21:46:16,862 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs+rhs] allocating threads: 1
2015-02-10 21:46:16,863 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lhs+rhs] starting step: (1/1) ...ipesplatform/groupbysplit
2015-02-10 21:46:16,864 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:16,865 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:16,903 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:16,921 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 21:46:16,936 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local690521345_0016
2015-02-10 21:46:16,954 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity690521345/.staging/job_local690521345_0016/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:16,955 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity690521345/.staging/job_local690521345_0016/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:17,006 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local690521345_0016/job_local690521345_0016.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:17,007 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local690521345_0016/job_local690521345_0016.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:17,008 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:17,008 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:17,009 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:17,009 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lhs+rhs] submitted hadoop job: job_local690521345_0016
2015-02-10 21:46:17,009 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lhs+rhs] tracking url: http://localhost:8080/
2015-02-10 21:46:17,011 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:17,012 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local690521345_0016_m_000000_0
2015-02-10 21:46:17,013 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:17,015 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/splitintermediate/part-00000
2015-02-10 21:46:17,015 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@596fde80
2015-02-10 21:46:17,016 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-10 21:46:17,016 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-10 21:46:17,158 INFO mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-10 21:46:17,159 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-10 21:46:17,159 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-10 21:46:17,159 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-10 21:46:17,159 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-10 21:46:17,160 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:17,160 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:17,165 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/splitintermediate"]
2015-02-10 21:46:17,166 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2015-02-10 21:46:17,168 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:17,169 INFO mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-10 21:46:17,169 INFO mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-10 21:46:17,169 INFO mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 150; bufvoid = 104857600
2015-02-10 21:46:17,169 INFO mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214360(104857440); length = 37/6553600
2015-02-10 21:46:17,172 INFO mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-10 21:46:17,175 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local690521345_0016_m_000000_0 is done. And is in the process of committing
2015-02-10 21:46:17,177 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/splitintermediate/part-00000:0+20
2015-02-10 21:46:17,177 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local690521345_0016_m_000000_0' done.
2015-02-10 21:46:17,177 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local690521345_0016_m_000000_0
2015-02-10 21:46:17,177 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:17,178 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-10 21:46:17,178 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local690521345_0016_r_000000_0
2015-02-10 21:46:17,179 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:17,180 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@7ddc5f7
2015-02-10 21:46:17,180 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-10 21:46:17,181 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local690521345_0016_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-10 21:46:17,183 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#6 about to shuffle output of map attempt_local690521345_0016_m_000000_0 decomp: 172 len: 176 to MEMORY
2015-02-10 21:46:17,183 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 172 bytes from map-output for attempt_local690521345_0016_m_000000_0
2015-02-10 21:46:17,183 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 172, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->172
2015-02-10 21:46:17,184 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-10 21:46:17,186 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:17,187 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-10 21:46:17,189 INFO mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-10 21:46:17,189 INFO mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 163 bytes
2015-02-10 21:46:17,190 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 172 bytes to disk to satisfy reduce memory limit
2015-02-10 21:46:17,190 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 176 bytes from disk
2015-02-10 21:46:17,191 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-10 21:46:17,191 INFO mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-10 21:46:17,191 INFO mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 163 bytes
2015-02-10 21:46:17,192 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:17,192 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-10 21:46:17,192 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-10 21:46:17,197 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2015-02-10 21:46:17,197 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/groupbysplit"]
2015-02-10 21:46:17,208 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local690521345_0016_r_000000_0 is done. And is in the process of committing
2015-02-10 21:46:17,210 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:17,210 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local690521345_0016_r_000000_0 is allowed to commit now
2015-02-10 21:46:17,211 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local690521345_0016_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/groupbysplit/_temporary/0/task_local690521345_0016_r_000000
2015-02-10 21:46:17,212 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-10 21:46:17,212 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local690521345_0016_r_000000_0' done.
2015-02-10 21:46:17,212 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local690521345_0016_r_000000_0
2015-02-10 21:46:17,212 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-10 21:46:17,230 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/groupbysplit/_temporary
2015-02-10 21:46:17,260 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:17,297 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:17,300 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/groupbysplit
2015-02-10 21:46:17,300 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/splitintermediate
2015-02-10 21:46:17,327 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 21:46:17,327 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-10 21:46:17,342 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:17,344 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:17,354 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 21:46:17,358 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [**&%&%bar:bar@foo://bl...] starting
2015-02-10 21:46:17,359 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [**&%&%bar:bar@foo://bl...] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 21:46:17,359 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [**&%&%bar:bar@foo://bl...] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/illegalchars"]
2015-02-10 21:46:17,359 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [**&%&%bar:bar@foo://bl...] parallel execution is enabled: false
2015-02-10 21:46:17,359 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [**&%&%bar:bar@foo://bl...] starting jobs: 2
2015-02-10 21:46:17,359 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [**&%&%bar:bar@foo://bl...] allocating threads: 1
2015-02-10 21:46:17,360 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [**&%&%bar:bar@foo://bl...] starting step: (1/2)
2015-02-10 21:46:17,361 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:17,363 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:17,390 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:17,409 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 21:46:17,430 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local2079224842_0017
2015-02-10 21:46:17,457 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity2079224842/.staging/job_local2079224842_0017/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:17,459 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity2079224842/.staging/job_local2079224842_0017/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:17,506 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2079224842_0017/job_local2079224842_0017.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:17,508 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2079224842_0017/job_local2079224842_0017.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:17,508 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:17,510 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:17,510 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:17,510 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [**&%&%bar:bar@foo://bl...] submitted hadoop job: job_local2079224842_0017
2015-02-10 21:46:17,511 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [**&%&%bar:bar@foo://bl...] tracking url: http://localhost:8080/
2015-02-10 21:46:17,513 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:17,513 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local2079224842_0017_m_000000_0
2015-02-10 21:46:17,515 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:17,516 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt
2015-02-10 21:46:17,517 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@17ad352e
2015-02-10 21:46:17,518 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-10 21:46:17,518 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-10 21:46:17,535 INFO mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-10 21:46:17,536 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-10 21:46:17,536 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-10 21:46:17,536 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-10 21:46:17,536 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-10 21:46:17,537 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:17,537 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:17,542 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 21:46:17,542 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2015-02-10 21:46:17,546 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:17,546 INFO mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-10 21:46:17,546 INFO mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-10 21:46:17,547 INFO mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 65; bufvoid = 104857600
2015-02-10 21:46:17,547 INFO mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214380(104857520); length = 17/6553600
2015-02-10 21:46:17,550 INFO mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-10 21:46:17,552 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local2079224842_0017_m_000000_0 is done. And is in the process of committing
2015-02-10 21:46:17,554 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt:0+30
2015-02-10 21:46:17,554 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local2079224842_0017_m_000000_0' done.
2015-02-10 21:46:17,554 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local2079224842_0017_m_000000_0
2015-02-10 21:46:17,555 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:17,555 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-10 21:46:17,555 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local2079224842_0017_r_000000_0
2015-02-10 21:46:17,557 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:17,557 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@486ab98
2015-02-10 21:46:17,559 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-10 21:46:17,559 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local2079224842_0017_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-10 21:46:17,561 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#7 about to shuffle output of map attempt_local2079224842_0017_m_000000_0 decomp: 77 len: 81 to MEMORY
2015-02-10 21:46:17,562 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 77 bytes from map-output for attempt_local2079224842_0017_m_000000_0
2015-02-10 21:46:17,562 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 77, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->77
2015-02-10 21:46:17,563 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-10 21:46:17,564 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:17,564 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-10 21:46:17,567 INFO mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-10 21:46:17,567 INFO mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 64 bytes
2015-02-10 21:46:17,568 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 77 bytes to disk to satisfy reduce memory limit
2015-02-10 21:46:17,569 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 81 bytes from disk
2015-02-10 21:46:17,569 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-10 21:46:17,570 INFO mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-10 21:46:17,570 INFO mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 64 bytes
2015-02-10 21:46:17,571 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:17,572 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-10 21:46:17,572 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-10 21:46:17,576 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2015-02-10 21:46:17,576 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[[UNKNOWN]->[ALL]]"][9409400639/__&%&%bar:bar@foo:_blah_/]
2015-02-10 21:46:17,600 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local2079224842_0017_r_000000_0 is done. And is in the process of committing
2015-02-10 21:46:17,602 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:17,602 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local2079224842_0017_r_000000_0 is allowed to commit now
2015-02-10 21:46:17,603 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local2079224842_0017_r_000000_0' to file:/tmp/hadoop-teamcity/9409400639____bar_bar_foo__blah__58642B369B6F4928B08FFAE76EE1905A/_temporary/0/task_local2079224842_0017_r_000000
2015-02-10 21:46:17,604 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-10 21:46:17,604 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local2079224842_0017_r_000000_0' done.
2015-02-10 21:46:17,605 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local2079224842_0017_r_000000_0
2015-02-10 21:46:17,605 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-10 21:46:17,620 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [**&%&%bar:bar@foo://bl...] starting step: (2/2) ...ipesplatform/illegalchars
2015-02-10 21:46:17,621 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:17,622 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:17,658 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:17,677 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 21:46:17,687 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:17,687 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:17,696 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local2054626680_0018
2015-02-10 21:46:17,717 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity2054626680/.staging/job_local2054626680_0018/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:17,718 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity2054626680/.staging/job_local2054626680_0018/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:17,777 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2054626680_0018/job_local2054626680_0018.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:17,778 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2054626680_0018/job_local2054626680_0018.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:17,779 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:17,780 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:17,780 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [**&%&%bar:bar@foo://bl...] submitted hadoop job: job_local2054626680_0018
2015-02-10 21:46:17,780 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:17,781 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [**&%&%bar:bar@foo://bl...] tracking url: http://localhost:8080/
2015-02-10 21:46:17,783 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:17,783 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local2054626680_0018_m_000000_0
2015-02-10 21:46:17,785 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:17,786 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/9409400639____bar_bar_foo__blah__58642B369B6F4928B08FFAE76EE1905A/part-00000
2015-02-10 21:46:17,787 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@643293ae
2015-02-10 21:46:17,798 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-10 21:46:17,799 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-10 21:46:17,963 INFO mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-10 21:46:17,964 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-10 21:46:17,964 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-10 21:46:17,964 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-10 21:46:17,964 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-10 21:46:17,965 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:17,965 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:17,970 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[[UNKNOWN]->[ALL]]"][9409400639/__&%&%bar:bar@foo:_blah_/]
2015-02-10 21:46:17,970 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2015-02-10 21:46:17,973 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:17,973 INFO mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-10 21:46:17,973 INFO mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-10 21:46:17,973 INFO mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 65; bufvoid = 104857600
2015-02-10 21:46:17,973 INFO mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214380(104857520); length = 17/6553600
2015-02-10 21:46:17,976 INFO mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-10 21:46:17,978 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local2054626680_0018_m_000000_0 is done. And is in the process of committing
2015-02-10 21:46:17,980 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-teamcity/9409400639____bar_bar_foo__blah__58642B369B6F4928B08FFAE76EE1905A/part-00000:0+170
2015-02-10 21:46:17,980 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local2054626680_0018_m_000000_0' done.
2015-02-10 21:46:17,980 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local2054626680_0018_m_000000_0
2015-02-10 21:46:17,980 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:17,981 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-10 21:46:17,981 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local2054626680_0018_r_000000_0
2015-02-10 21:46:17,983 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:17,983 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@2ccddcf6
2015-02-10 21:46:17,984 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-10 21:46:17,984 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local2054626680_0018_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-10 21:46:17,986 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#8 about to shuffle output of map attempt_local2054626680_0018_m_000000_0 decomp: 77 len: 81 to MEMORY
2015-02-10 21:46:17,987 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 77 bytes from map-output for attempt_local2054626680_0018_m_000000_0
2015-02-10 21:46:17,987 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 77, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->77
2015-02-10 21:46:17,988 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-10 21:46:17,989 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:17,989 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-10 21:46:17,997 INFO mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-10 21:46:17,998 INFO mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 64 bytes
2015-02-10 21:46:18,000 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 77 bytes to disk to satisfy reduce memory limit
2015-02-10 21:46:18,000 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 81 bytes from disk
2015-02-10 21:46:18,001 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-10 21:46:18,001 INFO mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-10 21:46:18,001 INFO mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 64 bytes
2015-02-10 21:46:18,003 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:18,003 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-10 21:46:18,003 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-10 21:46:18,008 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2015-02-10 21:46:18,008 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/illegalchars"]
2015-02-10 21:46:18,017 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local2054626680_0018_r_000000_0 is done. And is in the process of committing
2015-02-10 21:46:18,019 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 21:46:18,019 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local2054626680_0018_r_000000_0 is allowed to commit now
2015-02-10 21:46:18,020 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local2054626680_0018_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/illegalchars/_temporary/0/task_local2054626680_0018_r_000000
2015-02-10 21:46:18,021 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-10 21:46:18,021 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local2054626680_0018_r_000000_0' done.
2015-02-10 21:46:18,022 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local2054626680_0018_r_000000_0
2015-02-10 21:46:18,022 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-10 21:46:18,042 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/illegalchars/_temporary
2015-02-10 21:46:18,073 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:18,075 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/illegalchars
2015-02-10 21:46:18,095 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 21:46:18,095 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.6.3/9ae016e2b8d246b9c1de9168e715d9f1b971aa4a/cascading-hadoop2-mr1-2.6.3.jar
2015-02-10 21:46:18,102 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 21:46:18,105 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 21:46:18,106 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1009)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 21:46:18,111 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 21:46:18,112 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 21:46:18,112 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/ungrouped-unknown-nondeterministic"]
2015-02-10 21:46:18,112 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 21:46:18,113 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 21:46:18,113 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 21:46:18,114 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...-unknown-nondeterministic
2015-02-10 21:46:18,114 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:18,115 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 21:46:18,139 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:18,158 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 21:46:18,173 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local143579194_0019
2015-02-10 21:46:18,192 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity143579194/.staging/job_local143579194_0019/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:18,193 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/tmp/cascading/staging/teamcity143579194/.staging/job_local143579194_0019/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:18,241 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local143579194_0019/job_local143579194_0019.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 21:46:18,242 WARN conf.Configuration (Configuration.java:loadProperty(2358)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local143579194_0019/job_local143579194_0019.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 21:46:18,243 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 21:46:18,244 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local143579194_0019
2015-02-10 21:46:18,244 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 21:46:18,244 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 21:46:18,244 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 21:46:18,247 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 21:46:18,247 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local143579194_0019_m_000000_0
2015-02-10 21:46:18,249 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 21:46:18,250 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt
2015-02-10 21:46:18,250 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@31004e76
2015-02-10 21:46:18,252 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 21:46:18,258 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 21:46:18,259 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 21:46:18,263 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 21:46:18,263 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/ungrouped-unknown-nondeterministic"]
2015-02-10 21:46:18,266 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:18,267 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local143579194_0019_m_000000_0 is done. And is in the process of committing
2015-02-10 21:46:18,268 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 21:46:18,268 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local143579194_0019_m_000000_0 is allowed to commit now
2015-02-10 21:46:18,269 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local143579194_0019_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/ungrouped-unknown-nondeterministic/_temporary/0/task_local143579194_0019_m_000000
2015-02-10 21:46:18,270 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/classes/test/data/lower+upper.txt:0+30
2015-02-10 21:46:18,270 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local143579194_0019_m_000000_0' done.
2015-02-10 21:46:18,270 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local143579194_0019_m_000000_0
2015-02-10 21:46:18,271 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 21:46:18,288 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output/hadoop2-mr1/regressionpipesplatform/ungrouped-unknown-nondeterministic/_temporary
2015-02-10 21:46:18,318 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-10 21:46:18,320 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.4.x/build/test/output//hadoop2-mr1/regressionpipesplatform/ungrouped-unknown-nondeterministic