2015-02-10 19:54:55,518 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2015-02-10 19:54:55,591 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop2-mr1
2015-02-10 19:54:55,592 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.RegressionPipesPlatformTest
2015-02-10 19:54:55,639 INFO hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(105)) - not using cluster
2015-02-10 19:54:56,301 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 19:54:56,617 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 19:54:56,620 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 19:54:56,632 INFO property.AppProps (AppProps.java:getAppID(169)) - using app.id: 7E2107ABDD354F1C94B3C7FAC6D8303C
2015-02-10 19:54:56,711 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:54:56,753 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:54:56,757 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 19:54:56,885 INFO util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 2.6.3
2015-02-10 19:54:56,888 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 19:54:56,890 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lhs.txt"]
2015-02-10 19:54:56,890 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicor"]
2015-02-10 19:54:56,891 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 19:54:56,893 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 19:54:56,894 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 19:54:56,896 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...regression/complexlogicor
2015-02-10 19:54:56,921 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - session.id is deprecated. Instead, use dfs.metrics.session-id
2015-02-10 19:54:56,922 INFO jvm.JvmMetrics (JvmMetrics.java:init(76)) - Initializing JVM Metrics with processName=JobTracker, sessionId=
2015-02-10 19:54:56,948 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:54:57,336 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:54:57,380 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 19:54:57,537 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1843218034_0001
2015-02-10 19:54:57,587 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1843218034/.staging/job_local1843218034_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:54:57,588 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1843218034/.staging/job_local1843218034_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:54:57,768 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1843218034_0001/job_local1843218034_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:54:57,769 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1843218034_0001/job_local1843218034_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:54:57,776 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:54:57,778 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:54:57,780 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1843218034_0001
2015-02-10 19:54:57,781 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 19:54:57,781 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:54:57,840 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:54:57,843 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1843218034_0001_m_000000_0
2015-02-10 19:54:57,884 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:54:57,894 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lhs.txt
2015-02-10 19:54:57,895 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@40c07527
2015-02-10 19:54:57,904 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 19:54:57,922 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:54:57,923 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:54:57,970 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.task.partition is deprecated. Instead, use mapreduce.task.partition
2015-02-10 19:54:57,980 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lhs.txt"]
2015-02-10 19:54:57,981 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicor"]
2015-02-10 19:54:58,002 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:54:58,003 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1843218034_0001_m_000000_0 is done. And is in the process of committing
2015-02-10 19:54:58,014 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:54:58,015 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1843218034_0001_m_000000_0 is allowed to commit now
2015-02-10 19:54:58,017 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1843218034_0001_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicor/_temporary/0/task_local1843218034_0001_m_000000
2015-02-10 19:54:58,019 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lhs.txt:0+52
2015-02-10 19:54:58,020 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1843218034_0001_m_000000_0' done.
2015-02-10 19:54:58,020 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1843218034_0001_m_000000_0
2015-02-10 19:54:58,021 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:54:58,071 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicor/_temporary
2015-02-10 19:54:58,116 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:54:58,123 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/regression/complexlogicor
2015-02-10 19:54:58,160 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 19:54:58,161 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 19:54:58,175 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:54:58,181 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:54:58,182 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 19:54:58,193 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] starting
2015-02-10 19:54:58,194 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower.txt"]
2015-02-10 19:54:58,194 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/intermediate"]
2015-02-10 19:54:58,194 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] parallel execution is enabled: false
2015-02-10 19:54:58,194 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] starting jobs: 1
2015-02-10 19:54:58,194 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] allocating threads: 1
2015-02-10 19:54:58,195 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [split] starting step: (1/1) ...ipesplatform/intermediate
2015-02-10 19:54:58,196 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:54:58,198 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:54:58,233 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:54:58,258 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 19:54:58,299 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local976634542_0002
2015-02-10 19:54:58,323 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity976634542/.staging/job_local976634542_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:54:58,323 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity976634542/.staging/job_local976634542_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:54:58,411 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local976634542_0002/job_local976634542_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:54:58,412 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local976634542_0002/job_local976634542_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:54:58,414 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:54:58,414 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [split] submitted hadoop job: job_local976634542_0002
2015-02-10 19:54:58,414 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:54:58,414 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [split] tracking url: http://localhost:8080/
2015-02-10 19:54:58,414 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:54:58,419 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:54:58,419 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local976634542_0002_m_000000_0
2015-02-10 19:54:58,422 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:54:58,424 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower.txt
2015-02-10 19:54:58,424 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@69d4eeb5
2015-02-10 19:54:58,426 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 19:54:58,440 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:54:58,441 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:54:58,455 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower.txt"]
2015-02-10 19:54:58,456 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/intermediate"]
2015-02-10 19:54:58,460 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:54:58,460 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local976634542_0002_m_000000_0 is done. And is in the process of committing
2015-02-10 19:54:58,462 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:54:58,462 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local976634542_0002_m_000000_0 is allowed to commit now
2015-02-10 19:54:58,464 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local976634542_0002_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/intermediate/_temporary/0/task_local976634542_0002_m_000000
2015-02-10 19:54:58,465 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower.txt:0+19
2015-02-10 19:54:58,465 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local976634542_0002_m_000000_0' done.
2015-02-10 19:54:58,466 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local976634542_0002_m_000000_0
2015-02-10 19:54:58,466 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:54:58,493 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/intermediate/_temporary
2015-02-10 19:54:58,529 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 19:54:58,530 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 19:54:58,552 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:54:58,557 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:54:58,558 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 19:54:58,582 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs*rhs] starting
2015-02-10 19:54:58,583 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs*rhs] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/intermediate"]
2015-02-10 19:54:58,583 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs*rhs] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/cogroupsplit"]
2015-02-10 19:54:58,584 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs*rhs] parallel execution is enabled: false
2015-02-10 19:54:58,584 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs*rhs] starting jobs: 1
2015-02-10 19:54:58,585 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs*rhs] allocating threads: 1
2015-02-10 19:54:58,585 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lhs*rhs] starting step: (1/1) ...ipesplatform/cogroupsplit
2015-02-10 19:54:58,587 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:54:58,588 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:54:58,638 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:54:58,663 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 19:54:58,703 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local939788605_0003
2015-02-10 19:54:58,745 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity939788605/.staging/job_local939788605_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:54:58,746 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity939788605/.staging/job_local939788605_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:54:58,817 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local939788605_0003/job_local939788605_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:54:58,818 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local939788605_0003/job_local939788605_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:54:58,819 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:54:58,820 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:54:58,821 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:54:58,820 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lhs*rhs] submitted hadoop job: job_local939788605_0003
2015-02-10 19:54:58,822 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lhs*rhs] tracking url: http://localhost:8080/
2015-02-10 19:54:58,825 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:54:58,825 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local939788605_0003_m_000000_0
2015-02-10 19:54:58,828 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:54:58,830 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/intermediate/part-00000
2015-02-10 19:54:58,830 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@6648938
2015-02-10 19:54:58,833 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-10 19:54:58,841 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-10 19:54:59,013 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-10 19:54:59,013 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-10 19:54:59,013 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-10 19:54:59,014 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-10 19:54:59,014 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-10 19:54:59,034 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:54:59,034 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:54:59,058 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/intermediate"]
2015-02-10 19:54:59,058 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(lhs*rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num2']]
2015-02-10 19:54:59,065 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:54:59,065 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2015-02-10 19:54:59,065 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2015-02-10 19:54:59,065 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 140; bufvoid = 104857600
2015-02-10 19:54:59,065 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26214360(104857440); length = 37/6553600
2015-02-10 19:54:59,080 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2015-02-10 19:54:59,084 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local939788605_0003_m_000000_0 is done. And is in the process of committing
2015-02-10 19:54:59,087 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/intermediate/part-00000:0+20
2015-02-10 19:54:59,087 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local939788605_0003_m_000000_0' done.
2015-02-10 19:54:59,087 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local939788605_0003_m_000000_0
2015-02-10 19:54:59,088 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:54:59,090 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-10 19:54:59,091 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local939788605_0003_r_000000_0
2015-02-10 19:54:59,098 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:54:59,101 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@415b15ab
2015-02-10 19:54:59,115 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-10 19:54:59,119 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local939788605_0003_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-10 19:54:59,153 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#1 about to shuffle output of map attempt_local939788605_0003_m_000000_0 decomp: 162 len: 166 to MEMORY
2015-02-10 19:54:59,155 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 162 bytes from map-output for attempt_local939788605_0003_m_000000_0
2015-02-10 19:54:59,199 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 162, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->162
2015-02-10 19:54:59,200 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-10 19:54:59,202 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:54:59,202 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-10 19:54:59,212 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2015-02-10 19:54:59,212 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 152 bytes
2015-02-10 19:54:59,215 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 162 bytes to disk to satisfy reduce memory limit
2015-02-10 19:54:59,215 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 166 bytes from disk
2015-02-10 19:54:59,216 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-10 19:54:59,216 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2015-02-10 19:54:59,217 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 152 bytes
2015-02-10 19:54:59,218 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:54:59,219 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-10 19:54:59,220 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-10 19:54:59,235 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(lhs*rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num2']]
2015-02-10 19:54:59,235 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/cogroupsplit"]
2015-02-10 19:54:59,257 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-10 19:54:59,257 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-10 19:54:59,272 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local939788605_0003_r_000000_0 is done. And is in the process of committing
2015-02-10 19:54:59,274 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:54:59,274 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local939788605_0003_r_000000_0 is allowed to commit now
2015-02-10 19:54:59,275 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local939788605_0003_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/cogroupsplit/_temporary/0/task_local939788605_0003_r_000000
2015-02-10 19:54:59,277 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-10 19:54:59,277 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local939788605_0003_r_000000_0' done.
2015-02-10 19:54:59,277 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local939788605_0003_r_000000_0
2015-02-10 19:54:59,278 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-10 19:54:59,304 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/cogroupsplit/_temporary
2015-02-10 19:54:59,362 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:54:59,410 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:54:59,413 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/intermediate
2015-02-10 19:54:59,413 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/cogroupsplit
2015-02-10 19:54:59,442 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 19:54:59,443 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 19:54:59,456 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:54:59,461 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:54:59,463 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 19:54:59,476 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 19:54:59,476 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 19:54:59,476 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/none-unknown"]
2015-02-10 19:54:59,477 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 19:54:59,477 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 19:54:59,477 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 19:54:59,478 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...ipesplatform/none-unknown
2015-02-10 19:54:59,479 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:54:59,480 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:54:59,516 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:54:59,539 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 19:54:59,560 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1197323898_0004
2015-02-10 19:54:59,583 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1197323898/.staging/job_local1197323898_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:54:59,584 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1197323898/.staging/job_local1197323898_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:54:59,660 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1197323898_0004/job_local1197323898_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:54:59,660 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1197323898_0004/job_local1197323898_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:54:59,662 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:54:59,662 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1197323898_0004
2015-02-10 19:54:59,662 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 19:54:59,663 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:54:59,664 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:54:59,669 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:54:59,669 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1197323898_0004_m_000000_0
2015-02-10 19:54:59,673 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:54:59,675 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt
2015-02-10 19:54:59,676 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@4de514a9
2015-02-10 19:54:59,678 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-10 19:54:59,679 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-10 19:54:59,837 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-10 19:54:59,837 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-10 19:54:59,838 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-10 19:54:59,838 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-10 19:54:59,838 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-10 19:54:59,842 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:54:59,842 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:54:59,853 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 19:54:59,854 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{?}:NONE]]
2015-02-10 19:54:59,857 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:54:59,857 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2015-02-10 19:54:59,857 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2015-02-10 19:54:59,858 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 135; bufvoid = 104857600
2015-02-10 19:54:59,858 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26214380(104857520); length = 17/6553600
2015-02-10 19:54:59,862 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2015-02-10 19:54:59,864 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1197323898_0004_m_000000_0 is done. And is in the process of committing
2015-02-10 19:54:59,867 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt:0+30
2015-02-10 19:54:59,867 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1197323898_0004_m_000000_0' done.
2015-02-10 19:54:59,867 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1197323898_0004_m_000000_0
2015-02-10 19:54:59,868 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:54:59,868 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-10 19:54:59,869 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1197323898_0004_r_000000_0
2015-02-10 19:54:59,872 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:54:59,872 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@1ad997f9
2015-02-10 19:54:59,873 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-10 19:54:59,874 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1197323898_0004_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-10 19:54:59,876 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#2 about to shuffle output of map attempt_local1197323898_0004_m_000000_0 decomp: 147 len: 151 to MEMORY
2015-02-10 19:54:59,877 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 147 bytes from map-output for attempt_local1197323898_0004_m_000000_0
2015-02-10 19:54:59,878 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 147, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->147
2015-02-10 19:54:59,879 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-10 19:54:59,880 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:54:59,880 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-10 19:54:59,883 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2015-02-10 19:54:59,884 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 137 bytes
2015-02-10 19:54:59,886 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 147 bytes to disk to satisfy reduce memory limit
2015-02-10 19:54:59,886 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 151 bytes from disk
2015-02-10 19:54:59,887 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-10 19:54:59,887 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2015-02-10 19:54:59,887 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 137 bytes
2015-02-10 19:54:59,888 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:54:59,889 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-10 19:54:59,889 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-10 19:54:59,899 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{?}:NONE]]
2015-02-10 19:54:59,899 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/none-unknown"]
2015-02-10 19:54:59,914 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1197323898_0004_r_000000_0 is done. And is in the process of committing
2015-02-10 19:54:59,916 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:54:59,917 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1197323898_0004_r_000000_0 is allowed to commit now
2015-02-10 19:54:59,918 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1197323898_0004_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/none-unknown/_temporary/0/task_local1197323898_0004_r_000000
2015-02-10 19:54:59,921 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-10 19:54:59,921 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1197323898_0004_r_000000_0' done.
2015-02-10 19:54:59,922 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1197323898_0004_r_000000_0
2015-02-10 19:54:59,922 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-10 19:54:59,951 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/none-unknown/_temporary
2015-02-10 19:54:59,988 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:54:59,991 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/none-unknown
2015-02-10 19:55:00,017 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 19:55:00,018 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 19:55:00,027 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:55:00,033 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:55:00,035 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 19:55:00,050 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 19:55:00,050 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2015-02-10 19:55:00,051 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/oomepre"]
2015-02-10 19:55:00,052 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 19:55:00,052 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 19:55:00,052 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 19:55:00,053 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...sionpipesplatform/oomepre
2015-02-10 19:55:00,054 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:00,056 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:00,087 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:00,108 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 19:55:00,128 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local2115511414_0005
2015-02-10 19:55:00,149 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity2115511414/.staging/job_local2115511414_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:00,149 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity2115511414/.staging/job_local2115511414_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:00,222 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2115511414_0005/job_local2115511414_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:00,222 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local2115511414_0005/job_local2115511414_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:00,224 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:55:00,224 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local2115511414_0005
2015-02-10 19:55:00,225 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:55:00,225 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 19:55:00,225 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:55:00,230 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:55:00,230 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local2115511414_0005_m_000000_0
2015-02-10 19:55:00,233 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:00,235 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/apache.10.txt
2015-02-10 19:55:00,236 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@4a412f4b
2015-02-10 19:55:00,237 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 19:55:00,247 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:55:00,248 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:55:00,257 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2015-02-10 19:55:00,257 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/oomepre"]
2015-02-10 19:55:00,260 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 19:55:00,263 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:55:00,266 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local2115511414_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 19:55:00,277 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local2115511414_0005 state at FAILED
2015-02-10 19:55:00,277 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2015-02-10 19:55:00,278 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2015-02-10 19:55:00,279 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2015-02-10 19:55:00,279 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopping all jobs
2015-02-10 19:55:00,280 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...sionpipesplatform/oomepre
2015-02-10 19:55:00,281 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopped all jobs
2015-02-10 19:55:00,282 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/oomepre/_temporary
exception = cascading.flow.FlowException: local step failed
2015-02-10 19:55:00,284 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/oomepre
2015-02-10 19:55:00,319 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 19:55:00,319 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 19:55:00,327 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:55:00,331 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:55:00,332 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 19:55:00,338 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 19:55:00,339 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 19:55:00,339 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/copy"]
2015-02-10 19:55:00,339 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 19:55:00,340 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 19:55:00,340 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 19:55:00,341 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...ressionpipesplatform/copy
2015-02-10 19:55:00,342 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:00,344 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:00,373 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:00,418 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 19:55:00,436 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1130298118_0006
2015-02-10 19:55:00,456 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1130298118/.staging/job_local1130298118_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:00,456 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1130298118/.staging/job_local1130298118_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:00,511 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1130298118_0006/job_local1130298118_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:00,512 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1130298118_0006/job_local1130298118_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:00,513 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:55:00,513 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1130298118_0006
2015-02-10 19:55:00,514 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 19:55:00,514 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:55:00,514 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:55:00,518 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:55:00,518 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1130298118_0006_m_000000_0
2015-02-10 19:55:00,521 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:00,523 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt
2015-02-10 19:55:00,523 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@82f60ce
2015-02-10 19:55:00,527 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 19:55:00,536 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:55:00,537 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:55:00,542 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 19:55:00,543 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/copy"]
2015-02-10 19:55:00,546 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:00,546 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1130298118_0006_m_000000_0 is done. And is in the process of committing
2015-02-10 19:55:00,548 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:00,549 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1130298118_0006_m_000000_0 is allowed to commit now
2015-02-10 19:55:00,550 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1130298118_0006_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/copy/_temporary/0/task_local1130298118_0006_m_000000
2015-02-10 19:55:00,551 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt:0+30
2015-02-10 19:55:00,552 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1130298118_0006_m_000000_0' done.
2015-02-10 19:55:00,552 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1130298118_0006_m_000000_0
2015-02-10 19:55:00,553 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:55:00,570 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/copy/_temporary
2015-02-10 19:55:00,603 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:00,605 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/copy
2015-02-10 19:55:00,632 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 19:55:00,633 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 19:55:00,645 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:55:00,648 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:55:00,649 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 19:55:00,659 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 19:55:00,660 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 19:55:00,661 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/unknown-replace"]
2015-02-10 19:55:00,661 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 19:55:00,662 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 19:55:00,662 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 19:55:00,663 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...splatform/unknown-replace
2015-02-10 19:55:00,664 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:00,665 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:00,694 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:00,714 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 19:55:00,740 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local137467134_0007
2015-02-10 19:55:00,762 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity137467134/.staging/job_local137467134_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:00,762 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity137467134/.staging/job_local137467134_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:00,816 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local137467134_0007/job_local137467134_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:00,817 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local137467134_0007/job_local137467134_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:00,818 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:55:00,819 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:55:00,819 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:55:00,819 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local137467134_0007
2015-02-10 19:55:00,820 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 19:55:00,823 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:55:00,823 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local137467134_0007_m_000000_0
2015-02-10 19:55:00,825 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:00,828 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt
2015-02-10 19:55:00,829 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@79c0a077
2015-02-10 19:55:00,831 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 19:55:00,840 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:55:00,841 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:55:00,850 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 19:55:00,850 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextDelimited[[UNKNOWN]->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/unknown-replace"]
2015-02-10 19:55:00,854 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:00,856 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local137467134_0007_m_000000_0 is done. And is in the process of committing
2015-02-10 19:55:00,858 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:00,860 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local137467134_0007_m_000000_0 is allowed to commit now
2015-02-10 19:55:00,861 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local137467134_0007_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/unknown-replace/_temporary/0/task_local137467134_0007_m_000000
2015-02-10 19:55:00,863 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt:0+30
2015-02-10 19:55:00,864 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local137467134_0007_m_000000_0' done.
2015-02-10 19:55:00,864 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local137467134_0007_m_000000_0
2015-02-10 19:55:00,865 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:55:00,887 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/unknown-replace/_temporary
2015-02-10 19:55:00,921 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:00,955 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:00,958 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/unknown-replace
2015-02-10 19:55:00,986 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 19:55:00,987 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 19:55:01,001 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:55:01,004 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:55:01,005 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 19:55:01,016 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 19:55:01,016 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lhs.txt"]
2015-02-10 19:55:01,016 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicand"]
2015-02-10 19:55:01,016 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 19:55:01,016 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 19:55:01,017 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 19:55:01,017 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...egression/complexlogicand
2015-02-10 19:55:01,018 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:01,019 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:01,049 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:01,070 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 19:55:01,088 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1827605534_0008
2015-02-10 19:55:01,108 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1827605534/.staging/job_local1827605534_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:01,108 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1827605534/.staging/job_local1827605534_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:01,175 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1827605534_0008/job_local1827605534_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:01,175 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1827605534_0008/job_local1827605534_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:01,177 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:55:01,178 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1827605534_0008
2015-02-10 19:55:01,178 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:55:01,178 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 19:55:01,179 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:55:01,185 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:55:01,185 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1827605534_0008_m_000000_0
2015-02-10 19:55:01,187 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:01,190 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lhs.txt
2015-02-10 19:55:01,190 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@2e893a4a
2015-02-10 19:55:01,192 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 19:55:01,202 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:55:01,202 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:55:01,212 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lhs.txt"]
2015-02-10 19:55:01,212 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicand"]
2015-02-10 19:55:01,216 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:01,216 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1827605534_0008_m_000000_0 is done. And is in the process of committing
2015-02-10 19:55:01,218 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:01,218 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1827605534_0008_m_000000_0 is allowed to commit now
2015-02-10 19:55:01,219 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1827605534_0008_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicand/_temporary/0/task_local1827605534_0008_m_000000
2015-02-10 19:55:01,221 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lhs.txt:0+52
2015-02-10 19:55:01,221 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1827605534_0008_m_000000_0' done.
2015-02-10 19:55:01,221 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1827605534_0008_m_000000_0
2015-02-10 19:55:01,222 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:55:01,245 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicand/_temporary
2015-02-10 19:55:01,283 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:01,285 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/regression/complexlogicand
2015-02-10 19:55:01,318 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 19:55:01,318 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 19:55:01,331 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:55:01,334 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:55:01,335 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 19:55:01,345 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 19:55:01,345 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lhs.txt"]
2015-02-10 19:55:01,346 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicxor"]
2015-02-10 19:55:01,346 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 19:55:01,346 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 19:55:01,347 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 19:55:01,348 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...egression/complexlogicxor
2015-02-10 19:55:01,349 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:01,350 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:01,381 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:01,412 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 19:55:01,430 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1405106457_0009
2015-02-10 19:55:01,454 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1405106457/.staging/job_local1405106457_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:01,454 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1405106457/.staging/job_local1405106457_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:01,509 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1405106457_0009/job_local1405106457_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:01,509 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1405106457_0009/job_local1405106457_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:01,510 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:55:01,511 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1405106457_0009
2015-02-10 19:55:01,511 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:55:01,511 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 19:55:01,511 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:55:01,514 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:55:01,515 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1405106457_0009_m_000000_0
2015-02-10 19:55:01,517 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:01,518 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lhs.txt
2015-02-10 19:55:01,519 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@36656758
2015-02-10 19:55:01,520 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 19:55:01,529 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:55:01,529 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:55:01,538 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lhs.txt"]
2015-02-10 19:55:01,538 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicxor"]
2015-02-10 19:55:01,543 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:01,543 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1405106457_0009_m_000000_0 is done. And is in the process of committing
2015-02-10 19:55:01,545 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:01,545 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1405106457_0009_m_000000_0 is allowed to commit now
2015-02-10 19:55:01,546 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1405106457_0009_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicxor/_temporary/0/task_local1405106457_0009_m_000000
2015-02-10 19:55:01,547 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lhs.txt:0+52
2015-02-10 19:55:01,547 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1405106457_0009_m_000000_0' done.
2015-02-10 19:55:01,547 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1405106457_0009_m_000000_0
2015-02-10 19:55:01,549 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:55:01,569 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/regression/complexlogicxor/_temporary
2015-02-10 19:55:01,604 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:01,606 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/regression/complexlogicxor
2015-02-10 19:55:01,633 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 19:55:01,634 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 19:55:01,651 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:55:01,656 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:55:01,657 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 19:55:01,669 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lower*upper] starting
2015-02-10 19:55:01,669 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/upper.txt"]
2015-02-10 19:55:01,669 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lower*upper] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower.txt"]
2015-02-10 19:55:01,669 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lower*upper] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/oomepost"]
2015-02-10 19:55:01,670 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lower*upper] parallel execution is enabled: false
2015-02-10 19:55:01,670 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lower*upper] starting jobs: 1
2015-02-10 19:55:01,670 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lower*upper] allocating threads: 1
2015-02-10 19:55:01,670 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lower*upper] starting step: (1/1) ...ionpipesplatform/oomepost
2015-02-10 19:55:01,671 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:01,672 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:01,702 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:01,704 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:01,726 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:2
2015-02-10 19:55:01,743 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local186318955_0010
2015-02-10 19:55:01,762 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity186318955/.staging/job_local186318955_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:01,762 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity186318955/.staging/job_local186318955_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:01,815 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local186318955_0010/job_local186318955_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:01,815 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local186318955_0010/job_local186318955_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:01,817 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:55:01,817 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lower*upper] submitted hadoop job: job_local186318955_0010
2015-02-10 19:55:01,817 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lower*upper] tracking url: http://localhost:8080/
2015-02-10 19:55:01,818 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:55:01,818 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:55:01,823 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:55:01,824 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local186318955_0010_m_000000_0
2015-02-10 19:55:01,826 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:01,827 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower.txt
2015-02-10 19:55:01,828 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@2b04a681
2015-02-10 19:55:01,829 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-10 19:55:01,829 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-10 19:55:01,972 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-10 19:55:01,972 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-10 19:55:01,972 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-10 19:55:01,972 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-10 19:55:01,972 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-10 19:55:01,974 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:55:01,974 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:55:01,984 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower.txt"]
2015-02-10 19:55:01,985 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2015-02-10 19:55:01,988 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:01,988 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2015-02-10 19:55:01,988 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2015-02-10 19:55:01,988 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 85; bufvoid = 104857600
2015-02-10 19:55:01,988 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26214380(104857520); length = 17/6553600
2015-02-10 19:55:01,992 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2015-02-10 19:55:01,995 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local186318955_0010_m_000000_0 is done. And is in the process of committing
2015-02-10 19:55:01,997 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower.txt:0+19
2015-02-10 19:55:01,997 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local186318955_0010_m_000000_0' done.
2015-02-10 19:55:01,997 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local186318955_0010_m_000000_0
2015-02-10 19:55:01,998 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local186318955_0010_m_000001_0
2015-02-10 19:55:02,000 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:02,001 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/upper.txt
2015-02-10 19:55:02,002 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@76f9aa66
2015-02-10 19:55:02,003 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-10 19:55:02,004 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-10 19:55:02,146 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-10 19:55:02,147 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-10 19:55:02,147 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-10 19:55:02,147 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-10 19:55:02,147 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-10 19:55:02,150 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:55:02,150 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:55:02,163 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/upper.txt"]
2015-02-10 19:55:02,163 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2015-02-10 19:55:02,166 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:02,166 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2015-02-10 19:55:02,166 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2015-02-10 19:55:02,166 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 85; bufvoid = 104857600
2015-02-10 19:55:02,166 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26214380(104857520); length = 17/6553600
2015-02-10 19:55:02,171 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2015-02-10 19:55:02,173 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local186318955_0010_m_000001_0 is done. And is in the process of committing
2015-02-10 19:55:02,176 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/upper.txt:0+19
2015-02-10 19:55:02,176 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local186318955_0010_m_000001_0' done.
2015-02-10 19:55:02,176 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local186318955_0010_m_000001_0
2015-02-10 19:55:02,176 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:55:02,177 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-10 19:55:02,177 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local186318955_0010_r_000000_0
2015-02-10 19:55:02,181 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:02,181 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@397b6178
2015-02-10 19:55:02,184 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-10 19:55:02,186 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local186318955_0010_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-10 19:55:02,188 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#3 about to shuffle output of map attempt_local186318955_0010_m_000001_0 decomp: 97 len: 101 to MEMORY
2015-02-10 19:55:02,189 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 97 bytes from map-output for attempt_local186318955_0010_m_000001_0
2015-02-10 19:55:02,189 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 97, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->97
2015-02-10 19:55:02,193 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#3 about to shuffle output of map attempt_local186318955_0010_m_000000_0 decomp: 97 len: 101 to MEMORY
2015-02-10 19:55:02,194 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 97 bytes from map-output for attempt_local186318955_0010_m_000000_0
2015-02-10 19:55:02,196 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 97, inMemoryMapOutputs.size() -> 2, commitMemory -> 97, usedMemory ->194
2015-02-10 19:55:02,197 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-10 19:55:02,198 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 2 / 2 copied.
2015-02-10 19:55:02,199 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 2 in-memory map-outputs and 0 on-disk map-outputs
2015-02-10 19:55:02,202 INFO mapred.Merger (Merger.java:merge(589)) - Merging 2 sorted segments
2015-02-10 19:55:02,202 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 2 segments left of total size: 174 bytes
2015-02-10 19:55:02,204 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 2 segments, 194 bytes to disk to satisfy reduce memory limit
2015-02-10 19:55:02,205 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 196 bytes from disk
2015-02-10 19:55:02,205 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-10 19:55:02,205 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2015-02-10 19:55:02,205 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 182 bytes
2015-02-10 19:55:02,206 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 2 / 2 copied.
2015-02-10 19:55:02,207 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-10 19:55:02,207 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-10 19:55:02,217 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: CoGroup(lower*upper)[by: lower:[{1}:'num'] upper:[{1}:'num']]
2015-02-10 19:55:02,217 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/oomepost"]
2015-02-10 19:55:02,228 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(105)) - attempting to load codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-10 19:55:02,228 INFO collect.SpillableTupleList (SpillableTupleList.java:getCodecClass(110)) - found codec: org.apache.hadoop.io.compress.GzipCodec
2015-02-10 19:55:02,229 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 19:55:02,230 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-10 19:55:02,233 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local186318955_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 19:55:02,235 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [lower*upper] hadoop job job_local186318955_0010 state at FAILED
2015-02-10 19:55:02,236 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [lower*upper] failure info: NA
2015-02-10 19:55:02,237 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [lower*upper] task completion events identify failed tasks
2015-02-10 19:55:02,237 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [lower*upper] task completion events count: 0
2015-02-10 19:55:02,250 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lower*upper] stopping all jobs
2015-02-10 19:55:02,250 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lower*upper] stopping: (1/1) ...ionpipesplatform/oomepost
2015-02-10 19:55:02,251 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lower*upper] stopped all jobs
2015-02-10 19:55:02,251 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/oomepost/_temporary
exception = cascading.flow.FlowException: local step failed
2015-02-10 19:55:02,252 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/oomepost
2015-02-10 19:55:02,276 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 19:55:02,277 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 19:55:02,288 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:55:02,290 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:55:02,291 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 19:55:02,298 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 19:55:02,299 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2015-02-10 19:55:02,299 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/lasteachmodified"]
2015-02-10 19:55:02,299 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 19:55:02,299 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 19:55:02,299 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 19:55:02,301 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...platform/lasteachmodified
2015-02-10 19:55:02,301 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:02,303 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:02,332 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:02,363 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 19:55:02,383 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1046151793_0011
2015-02-10 19:55:02,406 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1046151793/.staging/job_local1046151793_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:02,407 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1046151793/.staging/job_local1046151793_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:02,461 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1046151793_0011/job_local1046151793_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:02,462 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1046151793_0011/job_local1046151793_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:02,463 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:55:02,464 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1046151793_0011
2015-02-10 19:55:02,464 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:55:02,464 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 19:55:02,464 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:55:02,467 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:55:02,468 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1046151793_0011_m_000000_0
2015-02-10 19:55:02,470 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:02,472 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/apache.10.txt
2015-02-10 19:55:02,472 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@5655d1b4
2015-02-10 19:55:02,474 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-10 19:55:02,475 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-10 19:55:02,547 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-10 19:55:02,548 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-10 19:55:02,548 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-10 19:55:02,548 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-10 19:55:02,548 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-10 19:55:02,550 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:55:02,550 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:55:02,558 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2015-02-10 19:55:02,558 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'insert']]
2015-02-10 19:55:02,562 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:02,562 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2015-02-10 19:55:02,562 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2015-02-10 19:55:02,562 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 160; bufvoid = 104857600
2015-02-10 19:55:02,562 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26214360(104857440); length = 37/6553600
2015-02-10 19:55:02,566 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2015-02-10 19:55:02,568 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1046151793_0011_m_000000_0 is done. And is in the process of committing
2015-02-10 19:55:02,571 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/apache.10.txt:0+1449
2015-02-10 19:55:02,571 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1046151793_0011_m_000000_0' done.
2015-02-10 19:55:02,571 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1046151793_0011_m_000000_0
2015-02-10 19:55:02,571 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:55:02,572 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-10 19:55:02,572 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1046151793_0011_r_000000_0
2015-02-10 19:55:02,575 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:02,576 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@756095fc
2015-02-10 19:55:02,577 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-10 19:55:02,578 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1046151793_0011_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-10 19:55:02,580 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#4 about to shuffle output of map attempt_local1046151793_0011_m_000000_0 decomp: 182 len: 186 to MEMORY
2015-02-10 19:55:02,581 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 182 bytes from map-output for attempt_local1046151793_0011_m_000000_0
2015-02-10 19:55:02,581 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 182, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->182
2015-02-10 19:55:02,582 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-10 19:55:02,583 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:55:02,585 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-10 19:55:02,589 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2015-02-10 19:55:02,589 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 166 bytes
2015-02-10 19:55:02,592 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 182 bytes to disk to satisfy reduce memory limit
2015-02-10 19:55:02,592 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 186 bytes from disk
2015-02-10 19:55:02,592 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-10 19:55:02,592 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2015-02-10 19:55:02,593 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 166 bytes
2015-02-10 19:55:02,594 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:55:02,595 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-10 19:55:02,595 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-10 19:55:02,602 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'insert']]
2015-02-10 19:55:02,603 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/lasteachmodified"]
2015-02-10 19:55:02,615 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1046151793_0011_r_000000_0 is done. And is in the process of committing
2015-02-10 19:55:02,617 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:55:02,618 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1046151793_0011_r_000000_0 is allowed to commit now
2015-02-10 19:55:02,618 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1046151793_0011_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/lasteachmodified/_temporary/0/task_local1046151793_0011_r_000000
2015-02-10 19:55:02,620 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-10 19:55:02,620 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1046151793_0011_r_000000_0' done.
2015-02-10 19:55:02,620 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1046151793_0011_r_000000_0
2015-02-10 19:55:02,621 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-10 19:55:02,647 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/lasteachmodified/_temporary
2015-02-10 19:55:02,692 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:02,694 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/lasteachmodified
2015-02-10 19:55:02,719 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 19:55:02,719 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 19:55:02,729 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:55:02,731 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:55:02,732 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 19:55:02,738 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 19:55:02,738 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 19:55:02,739 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/unknown"]
2015-02-10 19:55:02,739 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 19:55:02,739 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 19:55:02,739 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 19:55:02,740 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...sionpipesplatform/unknown
2015-02-10 19:55:02,741 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:02,742 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:02,768 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:02,788 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 19:55:02,804 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1429422295_0012
2015-02-10 19:55:02,822 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1429422295/.staging/job_local1429422295_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:02,823 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1429422295/.staging/job_local1429422295_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:02,872 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1429422295_0012/job_local1429422295_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:02,873 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1429422295_0012/job_local1429422295_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:02,874 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:55:02,875 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1429422295_0012
2015-02-10 19:55:02,875 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:55:02,875 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 19:55:02,875 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:55:02,878 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:55:02,878 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1429422295_0012_m_000000_0
2015-02-10 19:55:02,880 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:02,882 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt
2015-02-10 19:55:02,882 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@1e5cd7f9
2015-02-10 19:55:02,884 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 19:55:02,892 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:55:02,892 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:55:02,901 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 19:55:02,901 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/unknown"]
2015-02-10 19:55:02,904 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:02,905 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1429422295_0012_m_000000_0 is done. And is in the process of committing
2015-02-10 19:55:02,906 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:02,907 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1429422295_0012_m_000000_0 is allowed to commit now
2015-02-10 19:55:02,907 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1429422295_0012_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/unknown/_temporary/0/task_local1429422295_0012_m_000000
2015-02-10 19:55:02,909 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt:0+30
2015-02-10 19:55:02,909 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1429422295_0012_m_000000_0' done.
2015-02-10 19:55:02,909 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1429422295_0012_m_000000_0
2015-02-10 19:55:02,909 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:55:02,930 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/unknown/_temporary
2015-02-10 19:55:02,961 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:02,964 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/unknown
2015-02-10 19:55:02,988 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 19:55:02,989 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 19:55:02,996 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:55:02,999 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:55:03,000 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 19:55:03,008 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 19:55:03,009 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/critics.txt"]
2015-02-10 19:55:03,009 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/varwidth"]
2015-02-10 19:55:03,009 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 19:55:03,009 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 19:55:03,009 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 19:55:03,010 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...ionpipesplatform/varwidth
2015-02-10 19:55:03,011 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:03,012 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:03,038 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:03,057 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 19:55:03,073 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1531807866_0013
2015-02-10 19:55:03,091 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1531807866/.staging/job_local1531807866_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:03,092 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1531807866/.staging/job_local1531807866_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:03,143 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1531807866_0013/job_local1531807866_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:03,144 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1531807866_0013/job_local1531807866_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:03,146 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:55:03,146 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:55:03,147 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:55:03,146 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1531807866_0013
2015-02-10 19:55:03,147 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 19:55:03,149 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:55:03,150 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1531807866_0013_m_000000_0
2015-02-10 19:55:03,152 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:03,153 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/critics.txt
2015-02-10 19:55:03,153 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@3fe68ce4
2015-02-10 19:55:03,155 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 19:55:03,164 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:55:03,164 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:55:03,175 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/critics.txt"]
2015-02-10 19:55:03,175 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/varwidth"]
2015-02-10 19:55:03,180 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:03,180 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1531807866_0013_m_000000_0 is done. And is in the process of committing
2015-02-10 19:55:03,182 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:03,182 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1531807866_0013_m_000000_0 is allowed to commit now
2015-02-10 19:55:03,183 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1531807866_0013_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/varwidth/_temporary/0/task_local1531807866_0013_m_000000
2015-02-10 19:55:03,184 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/critics.txt:0+828
2015-02-10 19:55:03,184 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1531807866_0013_m_000000_0' done.
2015-02-10 19:55:03,185 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1531807866_0013_m_000000_0
2015-02-10 19:55:03,185 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:55:03,203 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/varwidth/_temporary
2015-02-10 19:55:03,236 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:03,239 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/varwidth
2015-02-10 19:55:03,678 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 19:55:03,678 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 19:55:04,247 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:55:04,250 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:55:04,251 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 19:55:04,377 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [pipeline] starting
2015-02-10 19:55:04,377 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [pipeline] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/apache.200.txt"]
2015-02-10 19:55:04,377 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [pipeline] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/deeppipline"]
2015-02-10 19:55:04,377 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [pipeline] parallel execution is enabled: false
2015-02-10 19:55:04,378 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [pipeline] starting jobs: 1
2015-02-10 19:55:04,378 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [pipeline] allocating threads: 1
2015-02-10 19:55:04,378 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pipeline] starting step: (1/1) ...pipesplatform/deeppipline
2015-02-10 19:55:04,382 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:04,383 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:04,411 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:04,432 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 19:55:04,450 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1268427122_0014
2015-02-10 19:55:04,471 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1268427122/.staging/job_local1268427122_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:04,472 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1268427122/.staging/job_local1268427122_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:04,525 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1268427122_0014/job_local1268427122_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:04,526 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1268427122_0014/job_local1268427122_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:04,527 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:55:04,527 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:55:04,528 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pipeline] submitted hadoop job: job_local1268427122_0014
2015-02-10 19:55:04,528 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [pipeline] tracking url: http://localhost:8080/
2015-02-10 19:55:04,528 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:55:04,531 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:55:04,531 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1268427122_0014_m_000000_0
2015-02-10 19:55:04,533 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:04,534 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/apache.200.txt
2015-02-10 19:55:04,534 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@34d6e7b8
2015-02-10 19:55:04,536 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-10 19:55:04,536 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-10 19:55:04,561 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-10 19:55:04,561 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-10 19:55:04,562 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-10 19:55:04,562 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-10 19:55:04,562 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-10 19:55:04,563 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:55:04,563 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:55:04,828 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/apache.200.txt"]
2015-02-10 19:55:04,828 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(pipeline)[by:[{1}:'hash']]
2015-02-10 19:55:05,101 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:05,102 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2015-02-10 19:55:05,102 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2015-02-10 19:55:05,102 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 35385; bufvoid = 104857600
2015-02-10 19:55:05,102 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26213600(104854400); length = 797/6553600
2015-02-10 19:55:05,131 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2015-02-10 19:55:05,134 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1268427122_0014_m_000000_0 is done. And is in the process of committing
2015-02-10 19:55:05,136 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/apache.200.txt:0+32599
2015-02-10 19:55:05,136 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1268427122_0014_m_000000_0' done.
2015-02-10 19:55:05,136 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1268427122_0014_m_000000_0
2015-02-10 19:55:05,136 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:55:05,137 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-10 19:55:05,137 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1268427122_0014_r_000000_0
2015-02-10 19:55:05,139 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:05,139 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@6b1f05a1
2015-02-10 19:55:05,140 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=503755552, maxSingleShuffleLimit=125938888, mergeThreshold=332478688, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-10 19:55:05,141 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1268427122_0014_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-10 19:55:05,142 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#5 about to shuffle output of map attempt_local1268427122_0014_m_000000_0 decomp: 35984 len: 35988 to MEMORY
2015-02-10 19:55:05,143 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 35984 bytes from map-output for attempt_local1268427122_0014_m_000000_0
2015-02-10 19:55:05,143 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 35984, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->35984
2015-02-10 19:55:05,144 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-10 19:55:05,145 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:55:05,145 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-10 19:55:05,148 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2015-02-10 19:55:05,148 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 35975 bytes
2015-02-10 19:55:05,153 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 35984 bytes to disk to satisfy reduce memory limit
2015-02-10 19:55:05,153 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 35988 bytes from disk
2015-02-10 19:55:05,153 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-10 19:55:05,153 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2015-02-10 19:55:05,154 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 35975 bytes
2015-02-10 19:55:05,155 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:55:05,155 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-10 19:55:05,155 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-10 19:55:05,282 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(pipeline)[by:[{1}:'hash']]
2015-02-10 19:55:05,283 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/deeppipline"]
2015-02-10 19:55:05,829 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1268427122_0014_r_000000_0 is done. And is in the process of committing
2015-02-10 19:55:05,831 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:55:05,831 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1268427122_0014_r_000000_0 is allowed to commit now
2015-02-10 19:55:05,832 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1268427122_0014_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/deeppipline/_temporary/0/task_local1268427122_0014_r_000000
2015-02-10 19:55:05,833 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-10 19:55:05,834 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1268427122_0014_r_000000_0' done.
2015-02-10 19:55:05,834 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1268427122_0014_r_000000_0
2015-02-10 19:55:05,834 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-10 19:55:05,858 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/deeppipline/_temporary
2015-02-10 19:55:05,859 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/deeppipline
2015-02-10 19:55:05,884 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 19:55:05,885 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 19:55:05,893 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:55:05,896 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:55:05,896 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 19:55:05,901 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] starting
2015-02-10 19:55:05,902 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] source: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower.txt"]
2015-02-10 19:55:05,902 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] sink: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/splitintermediate"]
2015-02-10 19:55:05,902 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] parallel execution is enabled: false
2015-02-10 19:55:05,902 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] starting jobs: 1
2015-02-10 19:55:05,902 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [split] allocating threads: 1
2015-02-10 19:55:05,904 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [split] starting step: (1/1) ...latform/splitintermediate
2015-02-10 19:55:05,905 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:05,907 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:05,933 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:05,955 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 19:55:05,975 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1850840343_0015
2015-02-10 19:55:05,998 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1850840343/.staging/job_local1850840343_0015/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:05,998 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1850840343/.staging/job_local1850840343_0015/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:06,064 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1850840343_0015/job_local1850840343_0015.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:06,064 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1850840343_0015/job_local1850840343_0015.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:06,066 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:55:06,066 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [split] submitted hadoop job: job_local1850840343_0015
2015-02-10 19:55:06,067 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [split] tracking url: http://localhost:8080/
2015-02-10 19:55:06,067 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:55:06,068 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:55:06,071 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:55:06,072 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1850840343_0015_m_000000_0
2015-02-10 19:55:06,074 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:06,077 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower.txt
2015-02-10 19:55:06,077 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@4c418cf
2015-02-10 19:55:06,079 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 19:55:06,087 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:55:06,087 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:55:06,092 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower.txt"]
2015-02-10 19:55:06,092 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/splitintermediate"]
2015-02-10 19:55:06,095 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:06,096 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1850840343_0015_m_000000_0 is done. And is in the process of committing
2015-02-10 19:55:06,097 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:06,097 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1850840343_0015_m_000000_0 is allowed to commit now
2015-02-10 19:55:06,098 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1850840343_0015_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/splitintermediate/_temporary/0/task_local1850840343_0015_m_000000
2015-02-10 19:55:06,099 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower.txt:0+19
2015-02-10 19:55:06,099 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1850840343_0015_m_000000_0' done.
2015-02-10 19:55:06,100 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1850840343_0015_m_000000_0
2015-02-10 19:55:06,100 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:55:06,122 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/splitintermediate/_temporary
2015-02-10 19:55:06,146 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 19:55:06,147 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 19:55:06,157 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:55:06,160 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:55:06,161 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 19:55:06,165 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs+rhs] starting
2015-02-10 19:55:06,166 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs+rhs] source: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/splitintermediate"]
2015-02-10 19:55:06,166 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs+rhs] sink: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/groupbysplit"]
2015-02-10 19:55:06,166 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs+rhs] parallel execution is enabled: false
2015-02-10 19:55:06,166 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs+rhs] starting jobs: 1
2015-02-10 19:55:06,166 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [lhs+rhs] allocating threads: 1
2015-02-10 19:55:06,167 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lhs+rhs] starting step: (1/1) ...ipesplatform/groupbysplit
2015-02-10 19:55:06,168 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:06,170 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:06,210 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:06,234 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/apache.10.txt:0+1449 > map
2015-02-10 19:55:06,239 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 19:55:06,254 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local448957882_0016
2015-02-10 19:55:06,273 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity448957882/.staging/job_local448957882_0016/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:06,274 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity448957882/.staging/job_local448957882_0016/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:06,323 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local448957882_0016/job_local448957882_0016.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:06,323 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local448957882_0016/job_local448957882_0016.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:06,325 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:55:06,325 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lhs+rhs] submitted hadoop job: job_local448957882_0016
2015-02-10 19:55:06,325 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:55:06,326 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:55:06,326 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [lhs+rhs] tracking url: http://localhost:8080/
2015-02-10 19:55:06,329 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:55:06,329 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local448957882_0016_m_000000_0
2015-02-10 19:55:06,330 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:06,332 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/splitintermediate/part-00000
2015-02-10 19:55:06,332 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@19a1d39
2015-02-10 19:55:06,334 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-10 19:55:06,334 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-10 19:55:06,352 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-10 19:55:06,352 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-10 19:55:06,353 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-10 19:55:06,353 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-10 19:55:06,353 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-10 19:55:06,354 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:55:06,354 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:55:06,360 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextDelimited[['num', 'char']]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/splitintermediate"]
2015-02-10 19:55:06,360 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2015-02-10 19:55:06,363 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:06,363 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2015-02-10 19:55:06,364 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2015-02-10 19:55:06,364 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 150; bufvoid = 104857600
2015-02-10 19:55:06,364 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26214360(104857440); length = 37/6553600
2015-02-10 19:55:06,368 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2015-02-10 19:55:06,370 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local448957882_0016_m_000000_0 is done. And is in the process of committing
2015-02-10 19:55:06,372 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/splitintermediate/part-00000:0+20
2015-02-10 19:55:06,372 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local448957882_0016_m_000000_0' done.
2015-02-10 19:55:06,373 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local448957882_0016_m_000000_0
2015-02-10 19:55:06,373 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:55:06,374 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-10 19:55:06,374 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local448957882_0016_r_000000_0
2015-02-10 19:55:06,376 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:06,376 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@1ba5cfae
2015-02-10 19:55:06,377 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=526693152, maxSingleShuffleLimit=131673288, mergeThreshold=347617504, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-10 19:55:06,378 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local448957882_0016_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-10 19:55:06,380 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#6 about to shuffle output of map attempt_local448957882_0016_m_000000_0 decomp: 172 len: 176 to MEMORY
2015-02-10 19:55:06,380 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 172 bytes from map-output for attempt_local448957882_0016_m_000000_0
2015-02-10 19:55:06,381 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 172, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->172
2015-02-10 19:55:06,382 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-10 19:55:06,383 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:55:06,383 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-10 19:55:06,385 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2015-02-10 19:55:06,386 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 163 bytes
2015-02-10 19:55:06,387 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 172 bytes to disk to satisfy reduce memory limit
2015-02-10 19:55:06,388 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 176 bytes from disk
2015-02-10 19:55:06,388 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-10 19:55:06,389 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2015-02-10 19:55:06,389 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 163 bytes
2015-02-10 19:55:06,390 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:55:06,390 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-10 19:55:06,391 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-10 19:55:06,396 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(lhs+rhs)[by: lhs:[{1}:'num'] rhs:[{1}:'num']]
2015-02-10 19:55:06,396 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/groupbysplit"]
2015-02-10 19:55:06,407 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local448957882_0016_r_000000_0 is done. And is in the process of committing
2015-02-10 19:55:06,409 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:55:06,409 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local448957882_0016_r_000000_0 is allowed to commit now
2015-02-10 19:55:06,410 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local448957882_0016_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/groupbysplit/_temporary/0/task_local448957882_0016_r_000000
2015-02-10 19:55:06,411 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-10 19:55:06,412 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local448957882_0016_r_000000_0' done.
2015-02-10 19:55:06,412 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local448957882_0016_r_000000_0
2015-02-10 19:55:06,413 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-10 19:55:06,437 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/groupbysplit/_temporary
2015-02-10 19:55:06,472 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:06,508 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:06,510 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/splitintermediate
2015-02-10 19:55:06,510 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/groupbysplit
2015-02-10 19:55:06,536 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 19:55:06,537 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 19:55:06,552 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:55:06,554 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:55:06,564 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 19:55:06,569 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [**&%&%bar:bar@foo://bl...] starting
2015-02-10 19:55:06,569 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.3.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 19:55:06,569 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.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/illegalchars"]
2015-02-10 19:55:06,570 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [**&%&%bar:bar@foo://bl...] parallel execution is enabled: false
2015-02-10 19:55:06,570 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [**&%&%bar:bar@foo://bl...] starting jobs: 2
2015-02-10 19:55:06,570 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [**&%&%bar:bar@foo://bl...] allocating threads: 1
2015-02-10 19:55:06,571 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [**&%&%bar:bar@foo://bl...] starting step: (1/2)
2015-02-10 19:55:06,571 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:06,572 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:06,597 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:06,616 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 19:55:06,632 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local445725034_0017
2015-02-10 19:55:06,649 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity445725034/.staging/job_local445725034_0017/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:06,650 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity445725034/.staging/job_local445725034_0017/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:06,709 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local445725034_0017/job_local445725034_0017.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:06,710 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local445725034_0017/job_local445725034_0017.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:06,711 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:55:06,712 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [**&%&%bar:bar@foo://bl...] submitted hadoop job: job_local445725034_0017
2015-02-10 19:55:06,712 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [**&%&%bar:bar@foo://bl...] tracking url: http://localhost:8080/
2015-02-10 19:55:06,712 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:55:06,713 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:55:06,716 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:55:06,716 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local445725034_0017_m_000000_0
2015-02-10 19:55:06,718 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:06,720 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt
2015-02-10 19:55:06,720 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@3f5735fd
2015-02-10 19:55:06,722 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-10 19:55:06,722 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-10 19:55:06,748 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-10 19:55:06,748 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-10 19:55:06,749 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-10 19:55:06,749 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-10 19:55:06,750 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-10 19:55:06,751 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:55:06,751 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:55:06,756 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 19:55:06,757 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2015-02-10 19:55:06,759 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:06,759 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2015-02-10 19:55:06,759 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2015-02-10 19:55:06,760 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 65; bufvoid = 104857600
2015-02-10 19:55:06,760 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26214380(104857520); length = 17/6553600
2015-02-10 19:55:06,763 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2015-02-10 19:55:06,764 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local445725034_0017_m_000000_0 is done. And is in the process of committing
2015-02-10 19:55:06,767 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt:0+30
2015-02-10 19:55:06,767 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local445725034_0017_m_000000_0' done.
2015-02-10 19:55:06,767 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local445725034_0017_m_000000_0
2015-02-10 19:55:06,767 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:55:06,768 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-10 19:55:06,768 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local445725034_0017_r_000000_0
2015-02-10 19:55:06,770 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:06,770 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@1aa9a7bb
2015-02-10 19:55:06,771 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=526830784, maxSingleShuffleLimit=131707696, mergeThreshold=347708320, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-10 19:55:06,772 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local445725034_0017_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-10 19:55:06,773 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#7 about to shuffle output of map attempt_local445725034_0017_m_000000_0 decomp: 77 len: 81 to MEMORY
2015-02-10 19:55:06,774 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 77 bytes from map-output for attempt_local445725034_0017_m_000000_0
2015-02-10 19:55:06,774 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 77, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->77
2015-02-10 19:55:06,775 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-10 19:55:06,776 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:55:06,776 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-10 19:55:06,780 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2015-02-10 19:55:06,780 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 64 bytes
2015-02-10 19:55:06,782 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 77 bytes to disk to satisfy reduce memory limit
2015-02-10 19:55:06,783 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 81 bytes from disk
2015-02-10 19:55:06,783 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-10 19:55:06,784 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2015-02-10 19:55:06,784 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 64 bytes
2015-02-10 19:55:06,785 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:55:06,786 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-10 19:55:06,786 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-10 19:55:06,790 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2015-02-10 19:55:06,791 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: TempHfs["SequenceFile[[UNKNOWN]->[ALL]]"][3388703217/__&%&%bar:bar@foo:_blah_/]
2015-02-10 19:55:06,815 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local445725034_0017_r_000000_0 is done. And is in the process of committing
2015-02-10 19:55:06,817 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:55:06,817 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local445725034_0017_r_000000_0 is allowed to commit now
2015-02-10 19:55:06,818 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local445725034_0017_r_000000_0' to file:/tmp/hadoop-teamcity/3388703217____bar_bar_foo__blah__C08203DA1D424334B725CDD0F0586945/_temporary/0/task_local445725034_0017_r_000000
2015-02-10 19:55:06,819 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-10 19:55:06,820 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local445725034_0017_r_000000_0' done.
2015-02-10 19:55:06,820 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local445725034_0017_r_000000_0
2015-02-10 19:55:06,821 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-10 19:55:06,841 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [**&%&%bar:bar@foo://bl...] starting step: (2/2) ...ipesplatform/illegalchars
2015-02-10 19:55:06,842 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:06,843 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:06,879 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:06,899 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 19:55:06,910 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:55:06,911 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:55:06,918 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1307464593_0018
2015-02-10 19:55:06,938 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1307464593/.staging/job_local1307464593_0018/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:06,938 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity1307464593/.staging/job_local1307464593_0018/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:06,992 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1307464593_0018/job_local1307464593_0018.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:06,992 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1307464593_0018/job_local1307464593_0018.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:06,993 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:55:06,993 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [**&%&%bar:bar@foo://bl...] submitted hadoop job: job_local1307464593_0018
2015-02-10 19:55:06,994 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:55:06,994 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [**&%&%bar:bar@foo://bl...] tracking url: http://localhost:8080/
2015-02-10 19:55:06,994 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:55:06,997 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:55:06,997 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1307464593_0018_m_000000_0
2015-02-10 19:55:06,999 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:07,001 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/tmp/hadoop-teamcity/3388703217____bar_bar_foo__blah__C08203DA1D424334B725CDD0F0586945/part-00000
2015-02-10 19:55:07,001 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@2deb9dd5
2015-02-10 19:55:07,012 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-10 19:55:07,012 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-10 19:55:07,038 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-10 19:55:07,038 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-10 19:55:07,038 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-10 19:55:07,038 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-10 19:55:07,039 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-10 19:55:07,041 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:55:07,041 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:55:07,046 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: TempHfs["SequenceFile[[UNKNOWN]->[ALL]]"][3388703217/__&%&%bar:bar@foo:_blah_/]
2015-02-10 19:55:07,046 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2015-02-10 19:55:07,049 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:07,049 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2015-02-10 19:55:07,049 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2015-02-10 19:55:07,050 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 65; bufvoid = 104857600
2015-02-10 19:55:07,050 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26214380(104857520); length = 17/6553600
2015-02-10 19:55:07,052 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2015-02-10 19:55:07,054 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1307464593_0018_m_000000_0 is done. And is in the process of committing
2015-02-10 19:55:07,056 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/tmp/hadoop-teamcity/3388703217____bar_bar_foo__blah__C08203DA1D424334B725CDD0F0586945/part-00000:0+170
2015-02-10 19:55:07,056 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1307464593_0018_m_000000_0' done.
2015-02-10 19:55:07,057 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1307464593_0018_m_000000_0
2015-02-10 19:55:07,057 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:55:07,058 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-10 19:55:07,058 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1307464593_0018_r_000000_0
2015-02-10 19:55:07,060 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:07,060 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@61bedd7d
2015-02-10 19:55:07,061 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=527060160, maxSingleShuffleLimit=131765040, mergeThreshold=347859712, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-10 19:55:07,062 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1307464593_0018_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-10 19:55:07,063 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#8 about to shuffle output of map attempt_local1307464593_0018_m_000000_0 decomp: 77 len: 81 to MEMORY
2015-02-10 19:55:07,064 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 77 bytes from map-output for attempt_local1307464593_0018_m_000000_0
2015-02-10 19:55:07,064 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 77, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->77
2015-02-10 19:55:07,065 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-10 19:55:07,066 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:55:07,066 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-10 19:55:07,070 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2015-02-10 19:55:07,070 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 64 bytes
2015-02-10 19:55:07,072 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 77 bytes to disk to satisfy reduce memory limit
2015-02-10 19:55:07,072 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 81 bytes from disk
2015-02-10 19:55:07,073 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-10 19:55:07,073 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2015-02-10 19:55:07,074 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 64 bytes
2015-02-10 19:55:07,074 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:55:07,075 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-10 19:55:07,075 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-10 19:55:07,080 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(**&%&%bar:bar@foo://blah/ (*(**^**&%&%^@#@&&() :::: ///\\ illegal chars in it)[by:[{1}:0]]
2015-02-10 19:55:07,080 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/illegalchars"]
2015-02-10 19:55:07,090 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local1307464593_0018_r_000000_0 is done. And is in the process of committing
2015-02-10 19:55:07,091 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-10 19:55:07,092 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local1307464593_0018_r_000000_0 is allowed to commit now
2015-02-10 19:55:07,093 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1307464593_0018_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/illegalchars/_temporary/0/task_local1307464593_0018_r_000000
2015-02-10 19:55:07,094 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-10 19:55:07,094 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local1307464593_0018_r_000000_0' done.
2015-02-10 19:55:07,095 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1307464593_0018_r_000000_0
2015-02-10 19:55:07,095 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-10 19:55:07,121 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/illegalchars/_temporary
2015-02-10 19:55:07,153 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:07,155 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/illegalchars
2015-02-10 19:55:07,175 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-10 19:55:07,175 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 19:55:07,181 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-10 19:55:07,183 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-10 19:55:07,184 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-10 19:55:07,189 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-10 19:55:07,189 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 19:55:07,190 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/ungrouped-unknown-nondeterministic"]
2015-02-10 19:55:07,190 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] parallel execution is enabled: false
2015-02-10 19:55:07,190 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting jobs: 1
2015-02-10 19:55:07,190 INFO flow.Flow (BaseFlow.java:logInfo(1378)) - [test] allocating threads: 1
2015-02-10 19:55:07,191 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...-unknown-nondeterministic
2015-02-10 19:55:07,191 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:07,193 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-10 19:55:07,218 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:07,236 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-10 19:55:07,252 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local36929747_0019
2015-02-10 19:55:07,271 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity36929747/.staging/job_local36929747_0019/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:07,272 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/tmp/cascading/staging/teamcity36929747/.staging/job_local36929747_0019/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:07,326 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local36929747_0019/job_local36929747_0019.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2015-02-10 19:55:07,327 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local36929747_0019/job_local36929747_0019.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2015-02-10 19:55:07,328 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-10 19:55:07,329 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local36929747_0019
2015-02-10 19:55:07,329 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-10 19:55:07,329 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-10 19:55:07,330 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-10 19:55:07,332 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-10 19:55:07,332 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local36929747_0019_m_000000_0
2015-02-10 19:55:07,334 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2015-02-10 19:55:07,335 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt
2015-02-10 19:55:07,336 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@62526d1d
2015-02-10 19:55:07,337 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2015-02-10 19:55:07,344 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-10 19:55:07,345 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-10 19:55:07,349 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt"]
2015-02-10 19:55:07,349 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/ungrouped-unknown-nondeterministic"]
2015-02-10 19:55:07,353 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:07,353 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local36929747_0019_m_000000_0 is done. And is in the process of committing
2015-02-10 19:55:07,354 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2015-02-10 19:55:07,354 INFO mapred.Task (Task.java:commit(1156)) - Task attempt_local36929747_0019_m_000000_0 is allowed to commit now
2015-02-10 19:55:07,355 INFO output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local36929747_0019_m_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/ungrouped-unknown-nondeterministic/_temporary/0/task_local36929747_0019_m_000000
2015-02-10 19:55:07,356 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/classes/test/data/lower+upper.txt:0+30
2015-02-10 19:55:07,357 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local36929747_0019_m_000000_0' done.
2015-02-10 19:55:07,357 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local36929747_0019_m_000000_0
2015-02-10 19:55:07,357 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-10 19:55:07,374 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output/hadoop2-mr1/regressionpipesplatform/ungrouped-unknown-nondeterministic/_temporary
2015-02-10 19:55:07,407 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2015-02-10 19:55:07,409 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.3.x/build/test/output//hadoop2-mr1/regressionpipesplatform/ungrouped-unknown-nondeterministic