Class cascading.operation.assertion.AppliedAssertionsPlatformTest

6

tests

0

failures

9.425s

duration

100%

successful

Tests

Test Duration Result
testGroupAssertionsFail 0.320s passed
testGroupAssertionsPass 0.375s passed
testGroupAssertionsRemoval 2.695s passed
testValueAssertionsFail 0.332s passed
testValueAssertionsPass 0.337s passed
testValueAssertionsRemoval 5.366s passed

Standard output

2015-02-11 00:27:02,677 INFO  platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2015-02-11 00:27:02,745 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop2-mr1
2015-02-11 00:27:02,745 INFO  platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.operation.assertion.AppliedAssertionsPlatformTest
2015-02-11 00:27:02,789 INFO  hadoop2.Hadoop2MR1Platform (Hadoop2MR1Platform.java:setUp(105)) - not using cluster
2015-02-11 00:27:03,465 WARN  util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2015-02-11 00:27:03,787 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-11 00:27:03,789 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-11 00:27:03,802 INFO  property.AppProps (AppProps.java:getAppID(169)) - using app.id: 44D59118E6BF410AAB14C34DFBC18899
2015-02-11 00:27:03,897 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-11 00:27:03,933 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-11 00:27:03,936 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-11 00:27:04,078 INFO  util.Version (Version.java:printBanner(82)) - Concurrent, Inc - Cascading 2.6.3
2015-02-11 00:27:04,081 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-11 00:27:04,082 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:04,084 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/NONE/STRICT"]
2015-02-11 00:27:04,085 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  parallel execution is enabled: false
2015-02-11 00:27:04,088 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  starting jobs: 1
2015-02-11 00:27:04,089 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  allocating threads: 1
2015-02-11 00:27:04,091 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...latform/value/NONE/STRICT
2015-02-11 00:27:04,118 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - session.id is deprecated. Instead, use dfs.metrics.session-id
2015-02-11 00:27:04,120 INFO  jvm.JvmMetrics (JvmMetrics.java:init(76)) - Initializing JVM Metrics with processName=JobTracker, sessionId=
2015-02-11 00:27:04,145 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:04,561 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:04,606 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-11 00:27:04,781 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1157790199_0001
2015-02-11 00:27:04,821 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity1157790199/.staging/job_local1157790199_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:04,828 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity1157790199/.staging/job_local1157790199_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:04,961 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1157790199_0001/job_local1157790199_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:04,964 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1157790199_0001/job_local1157790199_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:04,970 INFO  mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-11 00:27:04,971 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-11 00:27:04,974 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1157790199_0001
2015-02-11 00:27:04,974 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-11 00:27:04,974 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-11 00:27:05,018 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-11 00:27:05,022 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1157790199_0001_m_000000_0
2015-02-11 00:27:05,066 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:05,077 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt
2015-02-11 00:27:05,078 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@3e4ac866
2015-02-11 00:27:05,087 INFO  mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-11 00:27:05,094 INFO  mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-11 00:27:05,247 INFO  mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-11 00:27:05,247 INFO  mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-11 00:27:05,248 INFO  mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-11 00:27:05,248 INFO  mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-11 00:27:05,248 INFO  mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-11 00:27:05,273 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-11 00:27:05,274 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-11 00:27:05,327 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.task.partition is deprecated. Instead, use mapreduce.task.partition
2015-02-11 00:27:05,345 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:05,346 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:05,364 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-11 00:27:05,364 INFO  mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-11 00:27:05,364 INFO  mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-11 00:27:05,365 INFO  mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-11 00:27:05,365 INFO  mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-11 00:27:05,377 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-11 00:27:05,381 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1157790199_0001_m_000000_0 is done. And is in the process of committing
2015-02-11 00:27:05,407 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt:0+1449
2015-02-11 00:27:05,408 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1157790199_0001_m_000000_0' done.
2015-02-11 00:27:05,408 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1157790199_0001_m_000000_0
2015-02-11 00:27:05,408 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-11 00:27:05,411 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-11 00:27:05,412 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1157790199_0001_r_000000_0
2015-02-11 00:27:05,422 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:05,426 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@201532fc
2015-02-11 00:27:05,441 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-11 00:27:05,445 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1157790199_0001_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-11 00:27:05,482 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#1 about to shuffle output of map attempt_local1157790199_0001_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-11 00:27:05,488 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local1157790199_0001_m_000000_0
2015-02-11 00:27:05,536 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-11 00:27:05,537 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-11 00:27:05,539 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:05,539 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-11 00:27:05,550 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:05,550 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:05,554 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-11 00:27:05,555 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 713 bytes from disk
2015-02-11 00:27:05,556 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-11 00:27:05,557 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:05,557 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:05,559 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:05,561 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-11 00:27:05,561 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-11 00:27:05,583 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:05,583 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/NONE/STRICT"]
2015-02-11 00:27:05,615 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1157790199_0001_r_000000_0 is done. And is in the process of committing
2015-02-11 00:27:05,617 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:05,618 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local1157790199_0001_r_000000_0 is allowed to commit now
2015-02-11 00:27:05,619 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1157790199_0001_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/NONE/STRICT/_temporary/0/task_local1157790199_0001_r_000000
2015-02-11 00:27:05,621 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-11 00:27:05,621 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1157790199_0001_r_000000_0' done.
2015-02-11 00:27:05,621 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1157790199_0001_r_000000_0
2015-02-11 00:27:05,621 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-11 00:27:05,683 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/NONE/STRICT/_temporary
2015-02-11 00:27:05,727 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:05,766 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-11 00:27:05,767 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-11 00:27:05,790 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-11 00:27:05,796 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-11 00:27:05,797 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-11 00:27:05,811 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-11 00:27:05,811 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:05,811 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/VALID/STRICT"]
2015-02-11 00:27:05,812 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  parallel execution is enabled: false
2015-02-11 00:27:05,812 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  starting jobs: 1
2015-02-11 00:27:05,812 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  allocating threads: 1
2015-02-11 00:27:05,813 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...atform/value/VALID/STRICT
2015-02-11 00:27:05,815 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:05,817 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:05,854 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:05,897 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-11 00:27:05,938 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1266101775_0002
2015-02-11 00:27:05,966 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity1266101775/.staging/job_local1266101775_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:05,970 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity1266101775/.staging/job_local1266101775_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:06,054 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1266101775_0002/job_local1266101775_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:06,057 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1266101775_0002/job_local1266101775_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:06,058 INFO  mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-11 00:27:06,059 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1266101775_0002
2015-02-11 00:27:06,059 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-11 00:27:06,059 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-11 00:27:06,059 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-11 00:27:06,065 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-11 00:27:06,065 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1266101775_0002_m_000000_0
2015-02-11 00:27:06,068 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:06,071 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt
2015-02-11 00:27:06,071 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@22e38fca
2015-02-11 00:27:06,074 INFO  mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-11 00:27:06,074 INFO  mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-11 00:27:06,220 INFO  mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-11 00:27:06,221 INFO  mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-11 00:27:06,221 INFO  mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-11 00:27:06,221 INFO  mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-11 00:27:06,221 INFO  mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-11 00:27:06,223 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-11 00:27:06,224 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-11 00:27:06,241 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:06,242 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:06,249 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-11 00:27:06,249 INFO  mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-11 00:27:06,249 INFO  mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-11 00:27:06,249 INFO  mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-11 00:27:06,249 INFO  mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-11 00:27:06,256 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-11 00:27:06,260 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1266101775_0002_m_000000_0 is done. And is in the process of committing
2015-02-11 00:27:06,264 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt:0+1449
2015-02-11 00:27:06,266 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1266101775_0002_m_000000_0' done.
2015-02-11 00:27:06,267 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1266101775_0002_m_000000_0
2015-02-11 00:27:06,267 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-11 00:27:06,268 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-11 00:27:06,269 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1266101775_0002_r_000000_0
2015-02-11 00:27:06,272 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:06,272 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@2beb717e
2015-02-11 00:27:06,273 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-11 00:27:06,274 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1266101775_0002_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-11 00:27:06,278 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#2 about to shuffle output of map attempt_local1266101775_0002_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-11 00:27:06,279 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local1266101775_0002_m_000000_0
2015-02-11 00:27:06,279 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-11 00:27:06,280 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-11 00:27:06,281 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:06,282 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-11 00:27:06,285 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:06,285 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:06,287 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-11 00:27:06,288 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 713 bytes from disk
2015-02-11 00:27:06,288 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-11 00:27:06,288 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:06,289 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:06,289 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:06,291 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-11 00:27:06,292 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-11 00:27:06,307 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:06,307 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/VALID/STRICT"]
2015-02-11 00:27:06,323 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1266101775_0002_r_000000_0 is done. And is in the process of committing
2015-02-11 00:27:06,325 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:06,325 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local1266101775_0002_r_000000_0 is allowed to commit now
2015-02-11 00:27:06,326 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1266101775_0002_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/VALID/STRICT/_temporary/0/task_local1266101775_0002_r_000000
2015-02-11 00:27:06,328 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-11 00:27:06,328 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1266101775_0002_r_000000_0' done.
2015-02-11 00:27:06,328 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1266101775_0002_r_000000_0
2015-02-11 00:27:06,328 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-11 00:27:06,357 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/VALID/STRICT/_temporary
2015-02-11 00:27:06,416 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:06,454 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-11 00:27:06,455 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-11 00:27:06,475 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-11 00:27:06,480 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-11 00:27:06,481 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-11 00:27:06,498 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-11 00:27:06,498 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:06,499 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/STRICT/STRICT"]
2015-02-11 00:27:06,499 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  parallel execution is enabled: false
2015-02-11 00:27:06,500 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  starting jobs: 1
2015-02-11 00:27:06,500 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  allocating threads: 1
2015-02-11 00:27:06,501 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...tform/value/STRICT/STRICT
2015-02-11 00:27:06,502 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:06,504 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:06,538 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:06,563 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-11 00:27:06,642 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local935519054_0003
2015-02-11 00:27:06,668 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity935519054/.staging/job_local935519054_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:06,670 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity935519054/.staging/job_local935519054_0003/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:06,745 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local935519054_0003/job_local935519054_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:06,748 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local935519054_0003/job_local935519054_0003.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:06,749 INFO  mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-11 00:27:06,749 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local935519054_0003
2015-02-11 00:27:06,750 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-11 00:27:06,750 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-11 00:27:06,750 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-11 00:27:06,755 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-11 00:27:06,755 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local935519054_0003_m_000000_0
2015-02-11 00:27:06,757 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:06,760 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt
2015-02-11 00:27:06,760 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@57132e76
2015-02-11 00:27:06,764 INFO  mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-11 00:27:06,764 INFO  mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-11 00:27:06,929 INFO  mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-11 00:27:06,929 INFO  mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-11 00:27:06,929 INFO  mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-11 00:27:06,929 INFO  mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-11 00:27:06,930 INFO  mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-11 00:27:06,932 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-11 00:27:06,932 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-11 00:27:06,948 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:06,948 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:06,955 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-11 00:27:06,955 INFO  mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-11 00:27:06,956 INFO  mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-11 00:27:06,956 INFO  mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-11 00:27:06,956 INFO  mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-11 00:27:06,961 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-11 00:27:06,964 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local935519054_0003_m_000000_0 is done. And is in the process of committing
2015-02-11 00:27:06,967 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt:0+1449
2015-02-11 00:27:06,968 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local935519054_0003_m_000000_0' done.
2015-02-11 00:27:06,968 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local935519054_0003_m_000000_0
2015-02-11 00:27:06,968 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-11 00:27:06,969 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-11 00:27:06,969 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local935519054_0003_r_000000_0
2015-02-11 00:27:06,973 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:06,973 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@14cef147
2015-02-11 00:27:06,974 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-11 00:27:06,975 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local935519054_0003_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-11 00:27:06,977 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#3 about to shuffle output of map attempt_local935519054_0003_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-11 00:27:06,978 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local935519054_0003_m_000000_0
2015-02-11 00:27:06,978 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-11 00:27:06,979 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-11 00:27:06,981 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:06,981 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-11 00:27:06,984 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:06,985 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:06,989 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-11 00:27:06,989 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 713 bytes from disk
2015-02-11 00:27:06,990 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-11 00:27:06,990 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:06,990 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:06,991 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:06,992 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-11 00:27:06,992 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-11 00:27:07,006 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:07,006 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/STRICT/STRICT"]
2015-02-11 00:27:07,023 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runValueAssertions(AppliedAssertionsPlatformTest.java:158)] argument tuple: ['7'] was not equal to values: ['0']
	at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
	at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
	at cascading.operation.assertion.AssertEquals.doAssert(AssertEquals.java:77)
	at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:70)
	at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:34)
	at cascading.flow.stream.CloseReducingDuct.completeGroup(CloseReducingDuct.java:47)
	at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
	at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
	at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
	at cascading.operation.aggregator.Count.complete(Count.java:82)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.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-11 00:27:07,029 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runValueAssertions(AppliedAssertionsPlatformTest.java:158)] argument tuple: ['7'] was not equal to values: ['0']
	at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
	at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
	at cascading.operation.assertion.AssertEquals.doAssert(AssertEquals.java:77)
	at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:70)
	at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:34)
	at cascading.flow.stream.CloseReducingDuct.completeGroup(CloseReducingDuct.java:47)
	at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
	at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
	at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
	at cascading.operation.aggregator.Count.complete(Count.java:82)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.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-11 00:27:07,032 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-11 00:27:07,035 WARN  mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local935519054_0003
java.lang.Exception: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runValueAssertions(AppliedAssertionsPlatformTest.java:158)] argument tuple: ['7'] was not equal to values: ['0']
	at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
	at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:529)
Caused by: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runValueAssertions(AppliedAssertionsPlatformTest.java:158)] argument tuple: ['7'] was not equal to values: ['0']
	at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
	at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
	at cascading.operation.assertion.AssertEquals.doAssert(AssertEquals.java:77)
	at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:70)
	at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:34)
	at cascading.flow.stream.CloseReducingDuct.completeGroup(CloseReducingDuct.java:47)
	at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
	at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
	at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
	at cascading.operation.aggregator.Count.complete(Count.java:82)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.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-11 00:27:07,045 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local935519054_0003 state at FAILED
2015-02-11 00:27:07,045 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2015-02-11 00:27:07,046 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2015-02-11 00:27:07,046 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2015-02-11 00:27:07,059 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopping all jobs
2015-02-11 00:27:07,059 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...tform/value/STRICT/STRICT
2015-02-11 00:27:07,060 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopped all jobs
2015-02-11 00:27:07,060 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/STRICT/STRICT/_temporary
2015-02-11 00:27:07,097 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-11 00:27:07,098 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-11 00:27:07,120 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-11 00:27:07,126 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-11 00:27:07,127 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-11 00:27:07,138 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-11 00:27:07,139 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:07,139 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/NONE/VALID"]
2015-02-11 00:27:07,139 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  parallel execution is enabled: false
2015-02-11 00:27:07,140 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  starting jobs: 1
2015-02-11 00:27:07,140 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  allocating threads: 1
2015-02-11 00:27:07,140 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...platform/value/NONE/VALID
2015-02-11 00:27:07,142 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:07,144 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:07,179 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:07,218 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-11 00:27:07,242 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1527403370_0004
2015-02-11 00:27:07,265 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity1527403370/.staging/job_local1527403370_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:07,266 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity1527403370/.staging/job_local1527403370_0004/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:07,328 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1527403370_0004/job_local1527403370_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:07,329 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1527403370_0004/job_local1527403370_0004.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:07,330 INFO  mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-11 00:27:07,330 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1527403370_0004
2015-02-11 00:27:07,330 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-11 00:27:07,330 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-11 00:27:07,331 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-11 00:27:07,335 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-11 00:27:07,335 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1527403370_0004_m_000000_0
2015-02-11 00:27:07,338 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:07,340 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt
2015-02-11 00:27:07,340 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@53dffb78
2015-02-11 00:27:07,341 INFO  mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-11 00:27:07,342 INFO  mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-11 00:27:07,491 INFO  mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-11 00:27:07,492 INFO  mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-11 00:27:07,492 INFO  mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-11 00:27:07,492 INFO  mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-11 00:27:07,492 INFO  mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-11 00:27:07,493 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-11 00:27:07,494 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-11 00:27:07,506 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:07,506 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:07,512 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-11 00:27:07,513 INFO  mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-11 00:27:07,513 INFO  mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-11 00:27:07,513 INFO  mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-11 00:27:07,513 INFO  mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-11 00:27:07,517 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-11 00:27:07,520 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1527403370_0004_m_000000_0 is done. And is in the process of committing
2015-02-11 00:27:07,522 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt:0+1449
2015-02-11 00:27:07,523 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1527403370_0004_m_000000_0' done.
2015-02-11 00:27:07,523 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1527403370_0004_m_000000_0
2015-02-11 00:27:07,523 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-11 00:27:07,524 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-11 00:27:07,524 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1527403370_0004_r_000000_0
2015-02-11 00:27:07,527 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:07,527 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@2ac02d83
2015-02-11 00:27:07,528 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-11 00:27:07,529 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1527403370_0004_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-11 00:27:07,531 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#4 about to shuffle output of map attempt_local1527403370_0004_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-11 00:27:07,532 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local1527403370_0004_m_000000_0
2015-02-11 00:27:07,532 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-11 00:27:07,533 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-11 00:27:07,534 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:07,534 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-11 00:27:07,537 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:07,537 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:07,539 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-11 00:27:07,540 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 713 bytes from disk
2015-02-11 00:27:07,540 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-11 00:27:07,540 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:07,541 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:07,541 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:07,542 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-11 00:27:07,542 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-11 00:27:07,552 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:07,553 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/NONE/VALID"]
2015-02-11 00:27:07,567 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1527403370_0004_r_000000_0 is done. And is in the process of committing
2015-02-11 00:27:07,569 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:07,569 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local1527403370_0004_r_000000_0 is allowed to commit now
2015-02-11 00:27:07,570 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1527403370_0004_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/NONE/VALID/_temporary/0/task_local1527403370_0004_r_000000
2015-02-11 00:27:07,572 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-11 00:27:07,572 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1527403370_0004_r_000000_0' done.
2015-02-11 00:27:07,572 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1527403370_0004_r_000000_0
2015-02-11 00:27:07,573 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-11 00:27:07,595 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/NONE/VALID/_temporary
2015-02-11 00:27:07,632 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:07,663 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-11 00:27:07,664 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-11 00:27:07,685 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-11 00:27:07,690 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-11 00:27:07,691 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-11 00:27:07,703 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-11 00:27:07,703 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:07,704 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/VALID/VALID"]
2015-02-11 00:27:07,704 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  parallel execution is enabled: false
2015-02-11 00:27:07,704 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  starting jobs: 1
2015-02-11 00:27:07,704 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  allocating threads: 1
2015-02-11 00:27:07,705 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...latform/value/VALID/VALID
2015-02-11 00:27:07,707 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:07,708 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:07,740 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:07,763 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-11 00:27:07,784 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local808550810_0005
2015-02-11 00:27:07,808 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity808550810/.staging/job_local808550810_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:07,809 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity808550810/.staging/job_local808550810_0005/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:07,882 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local808550810_0005/job_local808550810_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:07,883 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local808550810_0005/job_local808550810_0005.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:07,884 INFO  mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-11 00:27:07,885 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local808550810_0005
2015-02-11 00:27:07,885 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-11 00:27:07,885 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-11 00:27:07,885 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-11 00:27:07,889 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-11 00:27:07,890 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local808550810_0005_m_000000_0
2015-02-11 00:27:07,893 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:07,895 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt
2015-02-11 00:27:07,896 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@372bab9
2015-02-11 00:27:07,897 INFO  mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-11 00:27:07,898 INFO  mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-11 00:27:08,056 INFO  mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-11 00:27:08,057 INFO  mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-11 00:27:08,057 INFO  mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-11 00:27:08,057 INFO  mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-11 00:27:08,057 INFO  mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-11 00:27:08,059 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-11 00:27:08,059 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-11 00:27:08,073 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:08,073 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:08,079 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-11 00:27:08,079 INFO  mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-11 00:27:08,080 INFO  mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-11 00:27:08,080 INFO  mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-11 00:27:08,080 INFO  mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-11 00:27:08,084 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-11 00:27:08,087 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local808550810_0005_m_000000_0 is done. And is in the process of committing
2015-02-11 00:27:08,090 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt:0+1449
2015-02-11 00:27:08,090 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local808550810_0005_m_000000_0' done.
2015-02-11 00:27:08,090 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local808550810_0005_m_000000_0
2015-02-11 00:27:08,091 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-11 00:27:08,091 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-11 00:27:08,092 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local808550810_0005_r_000000_0
2015-02-11 00:27:08,094 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:08,094 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@573577ca
2015-02-11 00:27:08,095 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-11 00:27:08,096 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local808550810_0005_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-11 00:27:08,098 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#5 about to shuffle output of map attempt_local808550810_0005_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-11 00:27:08,099 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local808550810_0005_m_000000_0
2015-02-11 00:27:08,099 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-11 00:27:08,099 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-11 00:27:08,101 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:08,101 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-11 00:27:08,104 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:08,104 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:08,106 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-11 00:27:08,106 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 713 bytes from disk
2015-02-11 00:27:08,107 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-11 00:27:08,107 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:08,107 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:08,108 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:08,108 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-11 00:27:08,109 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-11 00:27:08,120 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:08,120 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/VALID/VALID"]
2015-02-11 00:27:08,133 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runValueAssertions(AppliedAssertionsPlatformTest.java:158)] argument tuple: ['7'] was not equal to values: ['0']
	at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
	at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
	at cascading.operation.assertion.AssertEquals.doAssert(AssertEquals.java:77)
	at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:70)
	at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:34)
	at cascading.flow.stream.CloseReducingDuct.completeGroup(CloseReducingDuct.java:47)
	at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
	at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
	at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
	at cascading.operation.aggregator.Count.complete(Count.java:82)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.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-11 00:27:08,134 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runValueAssertions(AppliedAssertionsPlatformTest.java:158)] argument tuple: ['7'] was not equal to values: ['0']
	at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
	at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
	at cascading.operation.assertion.AssertEquals.doAssert(AssertEquals.java:77)
	at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:70)
	at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:34)
	at cascading.flow.stream.CloseReducingDuct.completeGroup(CloseReducingDuct.java:47)
	at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
	at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
	at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
	at cascading.operation.aggregator.Count.complete(Count.java:82)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.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-11 00:27:08,135 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-11 00:27:08,138 WARN  mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local808550810_0005
java.lang.Exception: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runValueAssertions(AppliedAssertionsPlatformTest.java:158)] argument tuple: ['7'] was not equal to values: ['0']
	at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
	at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:529)
Caused by: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runValueAssertions(AppliedAssertionsPlatformTest.java:158)] argument tuple: ['7'] was not equal to values: ['0']
	at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
	at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
	at cascading.operation.assertion.AssertEquals.doAssert(AssertEquals.java:77)
	at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:70)
	at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:34)
	at cascading.flow.stream.CloseReducingDuct.completeGroup(CloseReducingDuct.java:47)
	at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
	at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
	at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
	at cascading.operation.aggregator.Count.complete(Count.java:82)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.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-11 00:27:08,139 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local808550810_0005 state at FAILED
2015-02-11 00:27:08,139 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2015-02-11 00:27:08,139 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2015-02-11 00:27:08,140 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2015-02-11 00:27:08,148 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopping all jobs
2015-02-11 00:27:08,149 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...latform/value/VALID/VALID
2015-02-11 00:27:08,149 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopped all jobs
2015-02-11 00:27:08,150 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/VALID/VALID/_temporary
2015-02-11 00:27:08,151 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output//hadoop2-mr1/appliedassertionsplatform/value/STRICT/STRICT
2015-02-11 00:27:08,151 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output//hadoop2-mr1/appliedassertionsplatform/value/NONE/STRICT
2015-02-11 00:27:08,151 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output//hadoop2-mr1/appliedassertionsplatform/value/VALID/VALID
2015-02-11 00:27:08,152 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output//hadoop2-mr1/appliedassertionsplatform/value/VALID/STRICT
2015-02-11 00:27:08,152 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output//hadoop2-mr1/appliedassertionsplatform/value/NONE/VALID
2015-02-11 00:27:08,181 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-11 00:27:08,181 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-11 00:27:08,197 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-11 00:27:08,202 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-11 00:27:08,202 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-11 00:27:08,211 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-11 00:27:08,212 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:08,212 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/NONE/STRICT"]
2015-02-11 00:27:08,212 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  parallel execution is enabled: false
2015-02-11 00:27:08,212 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  starting jobs: 1
2015-02-11 00:27:08,213 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  allocating threads: 1
2015-02-11 00:27:08,213 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...latform/group/NONE/STRICT
2015-02-11 00:27:08,214 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:08,215 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:08,245 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:08,267 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-11 00:27:08,286 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1861715741_0006
2015-02-11 00:27:08,309 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity1861715741/.staging/job_local1861715741_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:08,310 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity1861715741/.staging/job_local1861715741_0006/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:08,369 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1861715741_0006/job_local1861715741_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:08,371 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1861715741_0006/job_local1861715741_0006.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:08,372 INFO  mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-11 00:27:08,372 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-11 00:27:08,372 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1861715741_0006
2015-02-11 00:27:08,373 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-11 00:27:08,373 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-11 00:27:08,377 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-11 00:27:08,377 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1861715741_0006_m_000000_0
2015-02-11 00:27:08,379 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:08,381 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt
2015-02-11 00:27:08,382 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@7e938b4a
2015-02-11 00:27:08,383 INFO  mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-11 00:27:08,384 INFO  mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-11 00:27:08,758 INFO  mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-11 00:27:08,759 INFO  mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-11 00:27:08,759 INFO  mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-11 00:27:08,759 INFO  mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-11 00:27:08,759 INFO  mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-11 00:27:08,761 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-11 00:27:08,761 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-11 00:27:08,772 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:08,772 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:08,777 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-11 00:27:08,778 INFO  mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-11 00:27:08,778 INFO  mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-11 00:27:08,778 INFO  mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-11 00:27:08,778 INFO  mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-11 00:27:08,782 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-11 00:27:08,785 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1861715741_0006_m_000000_0 is done. And is in the process of committing
2015-02-11 00:27:08,788 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt:0+1449
2015-02-11 00:27:08,788 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1861715741_0006_m_000000_0' done.
2015-02-11 00:27:08,788 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1861715741_0006_m_000000_0
2015-02-11 00:27:08,789 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-11 00:27:08,789 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-11 00:27:08,790 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1861715741_0006_r_000000_0
2015-02-11 00:27:08,792 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:08,792 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@4ffe0816
2015-02-11 00:27:08,793 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-11 00:27:08,794 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1861715741_0006_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-11 00:27:08,796 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#6 about to shuffle output of map attempt_local1861715741_0006_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-11 00:27:08,797 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local1861715741_0006_m_000000_0
2015-02-11 00:27:08,797 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-11 00:27:08,798 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-11 00:27:08,799 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:08,800 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-11 00:27:08,802 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:08,803 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:08,805 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-11 00:27:08,805 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 713 bytes from disk
2015-02-11 00:27:08,806 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-11 00:27:08,806 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:08,806 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:08,807 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:08,807 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-11 00:27:08,808 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-11 00:27:08,817 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:08,817 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/NONE/STRICT"]
2015-02-11 00:27:08,831 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1861715741_0006_r_000000_0 is done. And is in the process of committing
2015-02-11 00:27:08,833 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:08,834 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local1861715741_0006_r_000000_0 is allowed to commit now
2015-02-11 00:27:08,835 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1861715741_0006_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/NONE/STRICT/_temporary/0/task_local1861715741_0006_r_000000
2015-02-11 00:27:08,837 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-11 00:27:08,837 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1861715741_0006_r_000000_0' done.
2015-02-11 00:27:08,837 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1861715741_0006_r_000000_0
2015-02-11 00:27:08,837 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-11 00:27:08,947 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/NONE/STRICT/_temporary
2015-02-11 00:27:08,982 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:09,008 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-11 00:27:09,008 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-11 00:27:09,023 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-11 00:27:09,026 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-11 00:27:09,027 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-11 00:27:09,037 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-11 00:27:09,037 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:09,037 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/VALID/STRICT"]
2015-02-11 00:27:09,037 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  parallel execution is enabled: false
2015-02-11 00:27:09,037 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  starting jobs: 1
2015-02-11 00:27:09,038 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  allocating threads: 1
2015-02-11 00:27:09,038 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...atform/group/VALID/STRICT
2015-02-11 00:27:09,039 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:09,041 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:09,070 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:09,092 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-11 00:27:09,111 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1361739878_0007
2015-02-11 00:27:09,130 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity1361739878/.staging/job_local1361739878_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:09,131 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity1361739878/.staging/job_local1361739878_0007/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:09,188 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1361739878_0007/job_local1361739878_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:09,189 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1361739878_0007/job_local1361739878_0007.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:09,190 INFO  mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-11 00:27:09,190 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1361739878_0007
2015-02-11 00:27:09,190 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-11 00:27:09,190 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-11 00:27:09,191 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-11 00:27:09,195 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-11 00:27:09,195 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1361739878_0007_m_000000_0
2015-02-11 00:27:09,198 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:09,200 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt
2015-02-11 00:27:09,200 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@5b2b6037
2015-02-11 00:27:09,202 INFO  mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-11 00:27:09,203 INFO  mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-11 00:27:09,348 INFO  mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-11 00:27:09,349 INFO  mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-11 00:27:09,349 INFO  mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-11 00:27:09,349 INFO  mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-11 00:27:09,349 INFO  mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-11 00:27:09,351 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-11 00:27:09,351 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-11 00:27:09,360 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:09,361 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:09,365 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-11 00:27:09,365 INFO  mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-11 00:27:09,365 INFO  mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-11 00:27:09,365 INFO  mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-11 00:27:09,365 INFO  mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-11 00:27:09,369 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-11 00:27:09,372 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1361739878_0007_m_000000_0 is done. And is in the process of committing
2015-02-11 00:27:09,374 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt:0+1449
2015-02-11 00:27:09,375 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1361739878_0007_m_000000_0' done.
2015-02-11 00:27:09,375 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1361739878_0007_m_000000_0
2015-02-11 00:27:09,375 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-11 00:27:09,376 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-11 00:27:09,376 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1361739878_0007_r_000000_0
2015-02-11 00:27:09,378 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:09,378 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@4d12ee4f
2015-02-11 00:27:09,380 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-11 00:27:09,381 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1361739878_0007_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-11 00:27:09,383 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#7 about to shuffle output of map attempt_local1361739878_0007_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-11 00:27:09,384 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local1361739878_0007_m_000000_0
2015-02-11 00:27:09,384 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-11 00:27:09,385 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-11 00:27:09,386 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:09,386 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-11 00:27:09,389 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:09,390 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:09,392 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-11 00:27:09,392 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 713 bytes from disk
2015-02-11 00:27:09,393 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-11 00:27:09,393 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:09,393 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:09,394 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:09,394 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-11 00:27:09,395 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-11 00:27:09,403 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:09,404 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/VALID/STRICT"]
2015-02-11 00:27:09,417 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1361739878_0007_r_000000_0 is done. And is in the process of committing
2015-02-11 00:27:09,418 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:09,419 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local1361739878_0007_r_000000_0 is allowed to commit now
2015-02-11 00:27:09,419 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1361739878_0007_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/VALID/STRICT/_temporary/0/task_local1361739878_0007_r_000000
2015-02-11 00:27:09,421 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-11 00:27:09,421 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1361739878_0007_r_000000_0' done.
2015-02-11 00:27:09,421 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1361739878_0007_r_000000_0
2015-02-11 00:27:09,422 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-11 00:27:09,443 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/VALID/STRICT/_temporary
2015-02-11 00:27:09,476 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:09,503 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-11 00:27:09,504 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-11 00:27:09,518 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-11 00:27:09,522 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-11 00:27:09,523 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-11 00:27:09,536 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-11 00:27:09,536 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:09,536 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/STRICT/STRICT"]
2015-02-11 00:27:09,537 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  parallel execution is enabled: false
2015-02-11 00:27:09,537 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  starting jobs: 1
2015-02-11 00:27:09,538 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  allocating threads: 1
2015-02-11 00:27:09,538 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...tform/group/STRICT/STRICT
2015-02-11 00:27:09,539 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:09,541 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:09,569 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:09,591 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-11 00:27:09,611 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1705149948_0008
2015-02-11 00:27:09,632 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity1705149948/.staging/job_local1705149948_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:09,633 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity1705149948/.staging/job_local1705149948_0008/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:09,690 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1705149948_0008/job_local1705149948_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:09,692 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1705149948_0008/job_local1705149948_0008.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:09,692 INFO  mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-11 00:27:09,693 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1705149948_0008
2015-02-11 00:27:09,693 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-11 00:27:09,693 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-11 00:27:09,694 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-11 00:27:09,697 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-11 00:27:09,698 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1705149948_0008_m_000000_0
2015-02-11 00:27:09,700 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:09,701 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt
2015-02-11 00:27:09,702 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@7e4ab8b9
2015-02-11 00:27:09,704 INFO  mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-11 00:27:09,704 INFO  mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-11 00:27:09,854 INFO  mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-11 00:27:09,854 INFO  mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-11 00:27:09,854 INFO  mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-11 00:27:09,854 INFO  mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-11 00:27:09,854 INFO  mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-11 00:27:09,856 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-11 00:27:09,856 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-11 00:27:09,869 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:09,869 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:09,874 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-11 00:27:09,874 INFO  mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-11 00:27:09,875 INFO  mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-11 00:27:09,875 INFO  mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-11 00:27:09,875 INFO  mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-11 00:27:09,879 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-11 00:27:09,882 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1705149948_0008_m_000000_0 is done. And is in the process of committing
2015-02-11 00:27:09,885 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt:0+1449
2015-02-11 00:27:09,885 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1705149948_0008_m_000000_0' done.
2015-02-11 00:27:09,886 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1705149948_0008_m_000000_0
2015-02-11 00:27:09,886 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-11 00:27:09,887 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-11 00:27:09,887 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1705149948_0008_r_000000_0
2015-02-11 00:27:09,890 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:09,890 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@4402083d
2015-02-11 00:27:09,891 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-11 00:27:09,892 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1705149948_0008_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-11 00:27:09,894 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#8 about to shuffle output of map attempt_local1705149948_0008_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-11 00:27:09,894 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local1705149948_0008_m_000000_0
2015-02-11 00:27:09,894 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-11 00:27:09,897 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-11 00:27:09,900 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:09,900 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-11 00:27:09,903 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:09,903 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:09,905 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-11 00:27:09,906 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 713 bytes from disk
2015-02-11 00:27:09,906 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-11 00:27:09,906 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:09,907 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:09,907 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:09,908 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-11 00:27:09,908 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-11 00:27:09,918 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:09,918 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/STRICT/STRICT"]
2015-02-11 00:27:09,931 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runGroupAssertions(AppliedAssertionsPlatformTest.java:283)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
	at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
	at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
	at cascading.operation.assertion.AssertGroupBase.doAssert(AssertGroupBase.java:172)
	at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:125)
	at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:34)
	at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
	at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
	at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
	at cascading.operation.aggregator.Count.complete(Count.java:82)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.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-11 00:27:09,932 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runGroupAssertions(AppliedAssertionsPlatformTest.java:283)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
	at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
	at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
	at cascading.operation.assertion.AssertGroupBase.doAssert(AssertGroupBase.java:172)
	at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:125)
	at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:34)
	at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
	at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
	at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
	at cascading.operation.aggregator.Count.complete(Count.java:82)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.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-11 00:27:09,933 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-11 00:27:09,936 WARN  mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local1705149948_0008
java.lang.Exception: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runGroupAssertions(AppliedAssertionsPlatformTest.java:283)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
	at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
	at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:529)
Caused by: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runGroupAssertions(AppliedAssertionsPlatformTest.java:283)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
	at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
	at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
	at cascading.operation.assertion.AssertGroupBase.doAssert(AssertGroupBase.java:172)
	at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:125)
	at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:34)
	at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
	at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
	at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
	at cascading.operation.aggregator.Count.complete(Count.java:82)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.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-11 00:27:09,936 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local1705149948_0008 state at FAILED
2015-02-11 00:27:09,942 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2015-02-11 00:27:09,942 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2015-02-11 00:27:09,942 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2015-02-11 00:27:09,949 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopping all jobs
2015-02-11 00:27:09,950 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...tform/group/STRICT/STRICT
2015-02-11 00:27:09,950 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopped all jobs
2015-02-11 00:27:09,951 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/STRICT/STRICT/_temporary
2015-02-11 00:27:09,986 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-11 00:27:09,986 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-11 00:27:10,002 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-11 00:27:10,005 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-11 00:27:10,005 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-11 00:27:10,013 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-11 00:27:10,013 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:10,014 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/NONE/VALID"]
2015-02-11 00:27:10,014 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  parallel execution is enabled: false
2015-02-11 00:27:10,014 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  starting jobs: 1
2015-02-11 00:27:10,015 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  allocating threads: 1
2015-02-11 00:27:10,016 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...platform/group/NONE/VALID
2015-02-11 00:27:10,017 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:10,018 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:10,048 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:10,069 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-11 00:27:10,089 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1001504681_0009
2015-02-11 00:27:10,112 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity1001504681/.staging/job_local1001504681_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:10,113 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity1001504681/.staging/job_local1001504681_0009/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:10,170 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1001504681_0009/job_local1001504681_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:10,172 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1001504681_0009/job_local1001504681_0009.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:10,172 INFO  mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-11 00:27:10,173 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1001504681_0009
2015-02-11 00:27:10,173 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-11 00:27:10,173 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-11 00:27:10,173 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-11 00:27:10,177 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-11 00:27:10,177 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1001504681_0009_m_000000_0
2015-02-11 00:27:10,179 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:10,181 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt
2015-02-11 00:27:10,181 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@25e4e6db
2015-02-11 00:27:10,183 INFO  mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-11 00:27:10,183 INFO  mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-11 00:27:10,244 INFO  mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-11 00:27:10,245 INFO  mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-11 00:27:10,245 INFO  mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-11 00:27:10,245 INFO  mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-11 00:27:10,245 INFO  mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-11 00:27:10,246 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-11 00:27:10,247 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-11 00:27:10,256 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:10,256 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:10,261 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-11 00:27:10,261 INFO  mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-11 00:27:10,261 INFO  mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-11 00:27:10,261 INFO  mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-11 00:27:10,261 INFO  mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-11 00:27:10,265 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-11 00:27:10,268 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1001504681_0009_m_000000_0 is done. And is in the process of committing
2015-02-11 00:27:10,271 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt:0+1449
2015-02-11 00:27:10,271 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1001504681_0009_m_000000_0' done.
2015-02-11 00:27:10,271 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1001504681_0009_m_000000_0
2015-02-11 00:27:10,271 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-11 00:27:10,272 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-11 00:27:10,272 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1001504681_0009_r_000000_0
2015-02-11 00:27:10,274 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:10,275 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@5f43a515
2015-02-11 00:27:10,276 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-11 00:27:10,277 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1001504681_0009_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-11 00:27:10,279 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#9 about to shuffle output of map attempt_local1001504681_0009_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-11 00:27:10,280 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local1001504681_0009_m_000000_0
2015-02-11 00:27:10,281 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-11 00:27:10,282 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-11 00:27:10,283 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:10,283 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-11 00:27:10,286 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:10,286 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:10,296 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-11 00:27:10,296 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 713 bytes from disk
2015-02-11 00:27:10,296 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-11 00:27:10,297 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:10,297 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:10,298 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:10,299 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-11 00:27:10,299 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-11 00:27:10,307 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:10,307 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/NONE/VALID"]
2015-02-11 00:27:10,320 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1001504681_0009_r_000000_0 is done. And is in the process of committing
2015-02-11 00:27:10,322 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:10,322 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local1001504681_0009_r_000000_0 is allowed to commit now
2015-02-11 00:27:10,323 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1001504681_0009_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/NONE/VALID/_temporary/0/task_local1001504681_0009_r_000000
2015-02-11 00:27:10,324 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-11 00:27:10,325 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1001504681_0009_r_000000_0' done.
2015-02-11 00:27:10,325 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1001504681_0009_r_000000_0
2015-02-11 00:27:10,325 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-11 00:27:10,353 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/NONE/VALID/_temporary
2015-02-11 00:27:10,386 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:10,417 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-11 00:27:10,417 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-11 00:27:10,432 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-11 00:27:10,436 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-11 00:27:10,436 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-11 00:27:10,445 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-11 00:27:10,446 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:10,446 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/VALID/VALID"]
2015-02-11 00:27:10,446 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  parallel execution is enabled: false
2015-02-11 00:27:10,446 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  starting jobs: 1
2015-02-11 00:27:10,446 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  allocating threads: 1
2015-02-11 00:27:10,447 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...latform/group/VALID/VALID
2015-02-11 00:27:10,448 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:10,450 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:10,478 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:10,500 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-11 00:27:10,518 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local93458434_0010
2015-02-11 00:27:10,539 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity93458434/.staging/job_local93458434_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:10,540 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity93458434/.staging/job_local93458434_0010/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:10,601 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local93458434_0010/job_local93458434_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:10,602 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local93458434_0010/job_local93458434_0010.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:10,603 INFO  mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-11 00:27:10,604 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-11 00:27:10,604 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local93458434_0010
2015-02-11 00:27:10,604 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-11 00:27:10,604 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-11 00:27:10,608 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-11 00:27:10,609 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local93458434_0010_m_000000_0
2015-02-11 00:27:10,611 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:10,612 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt
2015-02-11 00:27:10,612 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@58b52f79
2015-02-11 00:27:10,614 INFO  mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-11 00:27:10,614 INFO  mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-11 00:27:10,762 INFO  mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-11 00:27:10,763 INFO  mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-11 00:27:10,763 INFO  mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-11 00:27:10,763 INFO  mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-11 00:27:10,763 INFO  mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-11 00:27:10,764 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-11 00:27:10,765 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-11 00:27:10,775 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:10,775 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:10,779 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-11 00:27:10,780 INFO  mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-11 00:27:10,780 INFO  mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-11 00:27:10,780 INFO  mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-11 00:27:10,780 INFO  mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-11 00:27:10,784 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-11 00:27:10,786 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local93458434_0010_m_000000_0 is done. And is in the process of committing
2015-02-11 00:27:10,788 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt:0+1449
2015-02-11 00:27:10,789 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local93458434_0010_m_000000_0' done.
2015-02-11 00:27:10,789 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local93458434_0010_m_000000_0
2015-02-11 00:27:10,789 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-11 00:27:10,790 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-11 00:27:10,790 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local93458434_0010_r_000000_0
2015-02-11 00:27:10,792 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:10,792 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@5388ebd2
2015-02-11 00:27:10,793 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-11 00:27:10,794 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local93458434_0010_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-11 00:27:10,796 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#10 about to shuffle output of map attempt_local93458434_0010_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-11 00:27:10,796 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local93458434_0010_m_000000_0
2015-02-11 00:27:10,796 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-11 00:27:10,797 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-11 00:27:10,798 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:10,798 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-11 00:27:10,801 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:10,801 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:10,804 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-11 00:27:10,806 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 713 bytes from disk
2015-02-11 00:27:10,806 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-11 00:27:10,806 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:10,807 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:10,808 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:10,809 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-11 00:27:10,809 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-11 00:27:10,819 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:10,819 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/VALID/VALID"]
2015-02-11 00:27:10,832 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runGroupAssertions(AppliedAssertionsPlatformTest.java:283)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
	at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
	at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
	at cascading.operation.assertion.AssertGroupBase.doAssert(AssertGroupBase.java:172)
	at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:125)
	at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:34)
	at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
	at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
	at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
	at cascading.operation.aggregator.Count.complete(Count.java:82)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.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-11 00:27:10,835 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runGroupAssertions(AppliedAssertionsPlatformTest.java:283)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
	at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
	at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
	at cascading.operation.assertion.AssertGroupBase.doAssert(AssertGroupBase.java:172)
	at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:125)
	at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:34)
	at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
	at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
	at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
	at cascading.operation.aggregator.Count.complete(Count.java:82)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.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-11 00:27:10,836 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-11 00:27:10,839 WARN  mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local93458434_0010
java.lang.Exception: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runGroupAssertions(AppliedAssertionsPlatformTest.java:283)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
	at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
	at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:529)
Caused by: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.runGroupAssertions(AppliedAssertionsPlatformTest.java:283)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
	at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
	at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
	at cascading.operation.assertion.AssertGroupBase.doAssert(AssertGroupBase.java:172)
	at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:125)
	at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:34)
	at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
	at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
	at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
	at cascading.operation.aggregator.Count.complete(Count.java:82)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.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-11 00:27:10,839 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local93458434_0010 state at FAILED
2015-02-11 00:27:10,840 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2015-02-11 00:27:10,841 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2015-02-11 00:27:10,841 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2015-02-11 00:27:10,847 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopping all jobs
2015-02-11 00:27:10,847 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...latform/group/VALID/VALID
2015-02-11 00:27:10,848 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopped all jobs
2015-02-11 00:27:10,849 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/group/VALID/VALID/_temporary
2015-02-11 00:27:10,849 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output//hadoop2-mr1/appliedassertionsplatform/group/VALID/VALID
2015-02-11 00:27:10,849 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output//hadoop2-mr1/appliedassertionsplatform/group/VALID/STRICT
2015-02-11 00:27:10,849 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output//hadoop2-mr1/appliedassertionsplatform/group/NONE/STRICT
2015-02-11 00:27:10,850 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output//hadoop2-mr1/appliedassertionsplatform/group/STRICT/STRICT
2015-02-11 00:27:10,850 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output//hadoop2-mr1/appliedassertionsplatform/group/NONE/VALID
2015-02-11 00:27:10,872 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-11 00:27:10,873 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-11 00:27:10,884 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-11 00:27:10,887 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-11 00:27:10,887 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-11 00:27:10,894 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-11 00:27:10,895 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:10,895 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/fail"]
2015-02-11 00:27:10,896 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  parallel execution is enabled: false
2015-02-11 00:27:10,896 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  starting jobs: 1
2015-02-11 00:27:10,897 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  allocating threads: 1
2015-02-11 00:27:10,898 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...edassertionsplatform/fail
2015-02-11 00:27:10,899 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:10,901 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:10,929 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:10,950 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-11 00:27:10,968 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local804743358_0011
2015-02-11 00:27:10,988 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity804743358/.staging/job_local804743358_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:10,989 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity804743358/.staging/job_local804743358_0011/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:11,043 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local804743358_0011/job_local804743358_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:11,044 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local804743358_0011/job_local804743358_0011.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:11,045 INFO  mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-11 00:27:11,046 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local804743358_0011
2015-02-11 00:27:11,046 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-11 00:27:11,046 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-11 00:27:11,046 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-11 00:27:11,050 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-11 00:27:11,050 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local804743358_0011_m_000000_0
2015-02-11 00:27:11,052 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:11,054 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt
2015-02-11 00:27:11,054 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@363bed68
2015-02-11 00:27:11,055 INFO  mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-11 00:27:11,056 INFO  mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-11 00:27:11,080 INFO  mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-11 00:27:11,082 INFO  mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-11 00:27:11,082 INFO  mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-11 00:27:11,083 INFO  mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-11 00:27:11,083 INFO  mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-11 00:27:11,084 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-11 00:27:11,086 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-11 00:27:11,097 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:11,097 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:11,104 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-11 00:27:11,104 INFO  mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-11 00:27:11,104 INFO  mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-11 00:27:11,104 INFO  mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-11 00:27:11,105 INFO  mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-11 00:27:11,108 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-11 00:27:11,111 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local804743358_0011_m_000000_0 is done. And is in the process of committing
2015-02-11 00:27:11,113 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt:0+1449
2015-02-11 00:27:11,113 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local804743358_0011_m_000000_0' done.
2015-02-11 00:27:11,114 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local804743358_0011_m_000000_0
2015-02-11 00:27:11,114 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-11 00:27:11,115 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-11 00:27:11,115 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local804743358_0011_r_000000_0
2015-02-11 00:27:11,117 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:11,117 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@5bcfa4b2
2015-02-11 00:27:11,118 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=513251744, maxSingleShuffleLimit=128312936, mergeThreshold=338746176, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-11 00:27:11,119 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local804743358_0011_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-11 00:27:11,121 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#11 about to shuffle output of map attempt_local804743358_0011_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-11 00:27:11,122 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local804743358_0011_m_000000_0
2015-02-11 00:27:11,122 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-11 00:27:11,123 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-11 00:27:11,126 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:11,127 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-11 00:27:11,130 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:11,130 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:11,132 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-11 00:27:11,132 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 713 bytes from disk
2015-02-11 00:27:11,133 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-11 00:27:11,133 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:11,133 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:11,134 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:11,134 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-11 00:27:11,134 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-11 00:27:11,144 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:11,145 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/fail"]
2015-02-11 00:27:11,155 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.testGroupAssertionsFail(AppliedAssertionsPlatformTest.java:236)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
	at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
	at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
	at cascading.operation.assertion.AssertGroupBase.doAssert(AssertGroupBase.java:172)
	at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:125)
	at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:34)
	at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
	at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
	at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
	at cascading.operation.aggregator.Count.complete(Count.java:82)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.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-11 00:27:11,156 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.testGroupAssertionsFail(AppliedAssertionsPlatformTest.java:236)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
	at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
	at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
	at cascading.operation.assertion.AssertGroupBase.doAssert(AssertGroupBase.java:172)
	at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:125)
	at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:34)
	at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
	at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
	at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
	at cascading.operation.aggregator.Count.complete(Count.java:82)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.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-11 00:27:11,157 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-11 00:27:11,159 WARN  mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local804743358_0011
java.lang.Exception: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.testGroupAssertionsFail(AppliedAssertionsPlatformTest.java:236)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
	at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
	at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:529)
Caused by: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.testGroupAssertionsFail(AppliedAssertionsPlatformTest.java:236)] group size: 7, is not equal to: 0, in group ['method']: ['POST']
	at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
	at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
	at cascading.operation.assertion.AssertGroupBase.doAssert(AssertGroupBase.java:172)
	at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:125)
	at cascading.flow.stream.GroupAssertionEveryStage.completeGroup(GroupAssertionEveryStage.java:34)
	at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
	at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
	at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
	at cascading.operation.aggregator.Count.complete(Count.java:82)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.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-11 00:27:11,161 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local804743358_0011 state at FAILED
2015-02-11 00:27:11,161 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2015-02-11 00:27:11,162 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2015-02-11 00:27:11,162 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2015-02-11 00:27:11,168 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopping all jobs
2015-02-11 00:27:11,170 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...edassertionsplatform/fail
2015-02-11 00:27:11,170 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopped all jobs
2015-02-11 00:27:11,171 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/fail/_temporary
2015-02-11 00:27:11,171 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output//hadoop2-mr1/appliedassertionsplatform/fail
2015-02-11 00:27:11,193 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-11 00:27:11,194 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-11 00:27:11,205 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-11 00:27:11,207 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-11 00:27:11,207 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-11 00:27:11,215 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-11 00:27:11,215 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:11,216 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/pass"]
2015-02-11 00:27:11,216 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  parallel execution is enabled: false
2015-02-11 00:27:11,216 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  starting jobs: 1
2015-02-11 00:27:11,216 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  allocating threads: 1
2015-02-11 00:27:11,218 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...edassertionsplatform/pass
2015-02-11 00:27:11,219 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:11,220 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:11,247 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:11,267 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-11 00:27:11,283 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local1360751626_0012
2015-02-11 00:27:11,304 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity1360751626/.staging/job_local1360751626_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:11,305 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity1360751626/.staging/job_local1360751626_0012/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:11,373 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1360751626_0012/job_local1360751626_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:11,375 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local1360751626_0012/job_local1360751626_0012.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:11,376 INFO  mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-11 00:27:11,376 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1360751626_0012
2015-02-11 00:27:11,376 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-11 00:27:11,376 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-11 00:27:11,377 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-11 00:27:11,380 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-11 00:27:11,381 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local1360751626_0012_m_000000_0
2015-02-11 00:27:11,383 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:11,385 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt
2015-02-11 00:27:11,385 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@fbc2e06
2015-02-11 00:27:11,386 INFO  mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-11 00:27:11,386 INFO  mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-11 00:27:11,411 INFO  mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-11 00:27:11,411 INFO  mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-11 00:27:11,411 INFO  mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-11 00:27:11,411 INFO  mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-11 00:27:11,412 INFO  mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-11 00:27:11,413 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-11 00:27:11,413 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-11 00:27:11,425 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:11,425 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:11,430 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-11 00:27:11,431 INFO  mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-11 00:27:11,431 INFO  mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-11 00:27:11,431 INFO  mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-11 00:27:11,431 INFO  mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-11 00:27:11,435 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-11 00:27:11,438 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1360751626_0012_m_000000_0 is done. And is in the process of committing
2015-02-11 00:27:11,440 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt:0+1449
2015-02-11 00:27:11,440 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1360751626_0012_m_000000_0' done.
2015-02-11 00:27:11,441 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local1360751626_0012_m_000000_0
2015-02-11 00:27:11,441 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-11 00:27:11,442 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-11 00:27:11,442 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local1360751626_0012_r_000000_0
2015-02-11 00:27:11,444 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:11,445 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@f5c0729
2015-02-11 00:27:11,445 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=516050112, maxSingleShuffleLimit=129012528, mergeThreshold=340593088, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-11 00:27:11,446 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local1360751626_0012_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-11 00:27:11,448 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#12 about to shuffle output of map attempt_local1360751626_0012_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-11 00:27:11,449 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local1360751626_0012_m_000000_0
2015-02-11 00:27:11,449 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-11 00:27:11,451 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-11 00:27:11,452 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:11,453 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-11 00:27:11,456 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:11,456 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:11,458 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-11 00:27:11,459 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 713 bytes from disk
2015-02-11 00:27:11,459 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-11 00:27:11,459 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:11,460 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:11,461 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:11,462 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-11 00:27:11,462 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-11 00:27:11,471 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:11,472 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/pass"]
2015-02-11 00:27:11,483 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local1360751626_0012_r_000000_0 is done. And is in the process of committing
2015-02-11 00:27:11,486 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:11,486 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local1360751626_0012_r_000000_0 is allowed to commit now
2015-02-11 00:27:11,487 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local1360751626_0012_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/pass/_temporary/0/task_local1360751626_0012_r_000000
2015-02-11 00:27:11,489 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-11 00:27:11,489 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local1360751626_0012_r_000000_0' done.
2015-02-11 00:27:11,489 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local1360751626_0012_r_000000_0
2015-02-11 00:27:11,490 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-11 00:27:11,513 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/pass/_temporary
2015-02-11 00:27:11,545 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:11,547 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output//hadoop2-mr1/appliedassertionsplatform/pass
2015-02-11 00:27:11,571 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-11 00:27:11,572 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-11 00:27:11,583 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-11 00:27:11,586 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-11 00:27:11,587 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-11 00:27:11,594 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-11 00:27:11,594 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:11,595 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/fail"]
2015-02-11 00:27:11,595 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  parallel execution is enabled: false
2015-02-11 00:27:11,595 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  starting jobs: 1
2015-02-11 00:27:11,596 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  allocating threads: 1
2015-02-11 00:27:11,597 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...rtionsplatform/value/fail
2015-02-11 00:27:11,598 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:11,599 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:11,627 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:11,647 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-11 00:27:11,665 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local445763449_0013
2015-02-11 00:27:11,684 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity445763449/.staging/job_local445763449_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:11,685 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity445763449/.staging/job_local445763449_0013/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:11,745 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local445763449_0013/job_local445763449_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:11,746 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local445763449_0013/job_local445763449_0013.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:11,747 INFO  mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-11 00:27:11,747 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local445763449_0013
2015-02-11 00:27:11,748 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-11 00:27:11,748 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-11 00:27:11,748 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-11 00:27:11,752 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-11 00:27:11,752 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local445763449_0013_m_000000_0
2015-02-11 00:27:11,754 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:11,756 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt
2015-02-11 00:27:11,757 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@a01ec0b
2015-02-11 00:27:11,758 INFO  mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-11 00:27:11,759 INFO  mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-11 00:27:11,783 INFO  mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-11 00:27:11,783 INFO  mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-11 00:27:11,784 INFO  mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-11 00:27:11,784 INFO  mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-11 00:27:11,785 INFO  mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-11 00:27:11,787 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-11 00:27:11,787 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-11 00:27:11,797 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:11,797 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:11,801 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-11 00:27:11,802 INFO  mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-11 00:27:11,802 INFO  mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-11 00:27:11,802 INFO  mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-11 00:27:11,802 INFO  mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-11 00:27:11,806 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-11 00:27:11,808 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local445763449_0013_m_000000_0 is done. And is in the process of committing
2015-02-11 00:27:11,810 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt:0+1449
2015-02-11 00:27:11,810 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local445763449_0013_m_000000_0' done.
2015-02-11 00:27:11,810 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local445763449_0013_m_000000_0
2015-02-11 00:27:11,811 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-11 00:27:11,811 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-11 00:27:11,812 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local445763449_0013_r_000000_0
2015-02-11 00:27:11,814 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:11,814 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@402c5f8a
2015-02-11 00:27:11,815 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=550640000, maxSingleShuffleLimit=137660000, mergeThreshold=363422400, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-11 00:27:11,815 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local445763449_0013_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-11 00:27:11,817 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#13 about to shuffle output of map attempt_local445763449_0013_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-11 00:27:11,818 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local445763449_0013_m_000000_0
2015-02-11 00:27:11,818 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-11 00:27:11,819 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-11 00:27:11,820 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:11,821 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-11 00:27:11,825 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:11,825 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:11,827 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-11 00:27:11,827 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 713 bytes from disk
2015-02-11 00:27:11,828 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-11 00:27:11,828 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:11,829 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:11,830 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:11,830 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-11 00:27:11,831 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-11 00:27:11,839 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:11,840 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/fail"]
2015-02-11 00:27:11,851 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.testValueAssertionsFail(AppliedAssertionsPlatformTest.java:111)] argument tuple: ['7'] was not equal to values: ['0']
	at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
	at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
	at cascading.operation.assertion.AssertEquals.doAssert(AssertEquals.java:77)
	at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:70)
	at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:34)
	at cascading.flow.stream.CloseReducingDuct.completeGroup(CloseReducingDuct.java:47)
	at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
	at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
	at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
	at cascading.operation.aggregator.Count.complete(Count.java:82)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.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-11 00:27:11,854 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.testValueAssertionsFail(AppliedAssertionsPlatformTest.java:111)] argument tuple: ['7'] was not equal to values: ['0']
	at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
	at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
	at cascading.operation.assertion.AssertEquals.doAssert(AssertEquals.java:77)
	at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:70)
	at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:34)
	at cascading.flow.stream.CloseReducingDuct.completeGroup(CloseReducingDuct.java:47)
	at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
	at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
	at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
	at cascading.operation.aggregator.Count.complete(Count.java:82)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.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-11 00:27:11,859 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-11 00:27:11,861 WARN  mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local445763449_0013
java.lang.Exception: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.testValueAssertionsFail(AppliedAssertionsPlatformTest.java:111)] argument tuple: ['7'] was not equal to values: ['0']
	at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
	at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:529)
Caused by: cascading.operation.AssertionException: [cascading.operation.assertion.AppliedAssertionsPlatformTest.testValueAssertionsFail(AppliedAssertionsPlatformTest.java:111)] argument tuple: ['7'] was not equal to values: ['0']
	at cascading.operation.assertion.BaseAssertion.throwFail(BaseAssertion.java:107)
	at cascading.operation.assertion.BaseAssertion.fail(BaseAssertion.java:86)
	at cascading.operation.assertion.AssertEquals.doAssert(AssertEquals.java:77)
	at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:70)
	at cascading.flow.stream.ValueAssertionEachStage.receive(ValueAssertionEachStage.java:34)
	at cascading.flow.stream.CloseReducingDuct.completeGroup(CloseReducingDuct.java:47)
	at cascading.flow.stream.AggregatorEveryStage$1.collect(AggregatorEveryStage.java:67)
	at cascading.tuple.TupleEntryCollector.safeCollect(TupleEntryCollector.java:145)
	at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
	at cascading.operation.aggregator.Count.complete(Count.java:82)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
	at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
	at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.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-11 00:27:11,870 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local445763449_0013 state at FAILED
2015-02-11 00:27:11,870 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2015-02-11 00:27:11,870 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2015-02-11 00:27:11,870 WARN  flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2015-02-11 00:27:11,878 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopping all jobs
2015-02-11 00:27:11,878 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...rtionsplatform/value/fail
2015-02-11 00:27:11,879 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] stopped all jobs
2015-02-11 00:27:11,879 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/fail/_temporary
2015-02-11 00:27:11,879 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output//hadoop2-mr1/appliedassertionsplatform/value/fail
2015-02-11 00:27:11,901 INFO  util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2015-02-11 00:27:11,901 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-11 00:27:11,911 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2015-02-11 00:27:11,913 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2015-02-11 00:27:11,914 INFO  Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(1019)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2015-02-11 00:27:11,919 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test] starting
2015-02-11 00:27:11,920 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:11,920 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/pass"]
2015-02-11 00:27:11,920 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  parallel execution is enabled: false
2015-02-11 00:27:11,920 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  starting jobs: 1
2015-02-11 00:27:11,920 INFO  flow.Flow (BaseFlow.java:logInfo(1378)) - [test]  allocating threads: 1
2015-02-11 00:27:11,921 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...rtionsplatform/value/pass
2015-02-11 00:27:11,921 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:11,923 INFO  jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2015-02-11 00:27:11,948 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:11,969 INFO  mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2015-02-11 00:27:11,985 INFO  mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local514605566_0014
2015-02-11 00:27:12,004 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity514605566/.staging/job_local514605566_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:12,005 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/tmp/cascading/staging/teamcity514605566/.staging/job_local514605566_0014/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:12,057 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local514605566_0014/job_local514605566_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval;  Ignoring.
2015-02-11 00:27:12,058 WARN  conf.Configuration (Configuration.java:loadProperty(2368)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local514605566_0014/job_local514605566_0014.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts;  Ignoring.
2015-02-11 00:27:12,059 INFO  mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2015-02-11 00:27:12,059 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local514605566_0014
2015-02-11 00:27:12,059 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2015-02-11 00:27:12,060 INFO  flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2015-02-11 00:27:12,060 INFO  mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2015-02-11 00:27:12,063 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2015-02-11 00:27:12,063 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local514605566_0014_m_000000_0
2015-02-11 00:27:12,065 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:12,067 INFO  io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt
2015-02-11 00:27:12,067 INFO  mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@1bd3ecae
2015-02-11 00:27:12,069 INFO  mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2015-02-11 00:27:12,069 INFO  mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2015-02-11 00:27:12,093 INFO  mapred.MapTask (MapTask.java:setEquator(1182)) - (EQUATOR) 0 kvi 26214396(104857584)
2015-02-11 00:27:12,093 INFO  mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2015-02-11 00:27:12,093 INFO  mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2015-02-11 00:27:12,093 INFO  mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2015-02-11 00:27:12,094 INFO  mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2015-02-11 00:27:12,095 INFO  hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.6.3
2015-02-11 00:27:12,095 INFO  hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2015-02-11 00:27:12,106 INFO  hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt"]
2015-02-11 00:27:12,106 INFO  hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:12,111 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 
2015-02-11 00:27:12,111 INFO  mapred.MapTask (MapTask.java:flush(1437)) - Starting flush of map output
2015-02-11 00:27:12,111 INFO  mapred.MapTask (MapTask.java:flush(1455)) - Spilling map output
2015-02-11 00:27:12,111 INFO  mapred.MapTask (MapTask.java:flush(1456)) - bufstart = 0; bufend = 693; bufvoid = 104857600
2015-02-11 00:27:12,112 INFO  mapred.MapTask (MapTask.java:flush(1458)) - kvstart = 26214396(104857584); kvend = 26214372(104857488); length = 25/6553600
2015-02-11 00:27:12,115 INFO  mapred.MapTask (MapTask.java:sortAndSpill(1641)) - Finished spill 0
2015-02-11 00:27:12,118 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local514605566_0014_m_000000_0 is done. And is in the process of committing
2015-02-11 00:27:12,120 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/classes/test/data/apache.10.txt:0+1449
2015-02-11 00:27:12,120 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local514605566_0014_m_000000_0' done.
2015-02-11 00:27:12,120 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local514605566_0014_m_000000_0
2015-02-11 00:27:12,121 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2015-02-11 00:27:12,121 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2015-02-11 00:27:12,121 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local514605566_0014_r_000000_0
2015-02-11 00:27:12,123 INFO  mapred.Task (Task.java:initialize(587)) -  Using ResourceCalculatorProcessTree : [ ]
2015-02-11 00:27:12,124 INFO  mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@3e554058
2015-02-11 00:27:12,124 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=550823488, maxSingleShuffleLimit=137705872, mergeThreshold=363543520, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2015-02-11 00:27:12,125 INFO  reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local514605566_0014_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2015-02-11 00:27:12,127 INFO  reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#14 about to shuffle output of map attempt_local514605566_0014_m_000000_0 decomp: 709 len: 713 to MEMORY
2015-02-11 00:27:12,128 INFO  reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 709 bytes from map-output for attempt_local514605566_0014_m_000000_0
2015-02-11 00:27:12,128 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 709, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->709
2015-02-11 00:27:12,129 INFO  reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2015-02-11 00:27:12,130 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:12,130 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2015-02-11 00:27:12,133 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:12,133 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:12,135 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 709 bytes to disk to satisfy reduce memory limit
2015-02-11 00:27:12,135 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 713 bytes from disk
2015-02-11 00:27:12,135 INFO  reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2015-02-11 00:27:12,135 INFO  mapred.Merger (Merger.java:merge(591)) - Merging 1 sorted segments
2015-02-11 00:27:12,136 INFO  mapred.Merger (Merger.java:merge(690)) - Down to the last merge-pass, with 1 segments left of total size: 697 bytes
2015-02-11 00:27:12,136 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:12,137 INFO  hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.6.3
2015-02-11 00:27:12,137 INFO  hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2015-02-11 00:27:12,145 INFO  hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2015-02-11 00:27:12,145 INFO  hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/pass"]
2015-02-11 00:27:12,157 INFO  mapred.Task (Task.java:done(1001)) - Task:attempt_local514605566_0014_r_000000_0 is done. And is in the process of committing
2015-02-11 00:27:12,158 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2015-02-11 00:27:12,159 INFO  mapred.Task (Task.java:commit(1162)) - Task attempt_local514605566_0014_r_000000_0 is allowed to commit now
2015-02-11 00:27:12,159 INFO  output.FileOutputCommitter (FileOutputCommitter.java:commitTask(439)) - Saved output of task 'attempt_local514605566_0014_r_000000_0' to file:/opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/pass/_temporary/0/task_local514605566_0014_r_000000
2015-02-11 00:27:12,161 INFO  mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2015-02-11 00:27:12,161 INFO  mapred.Task (Task.java:sendDone(1121)) - Task 'attempt_local514605566_0014_r_000000_0' done.
2015-02-11 00:27:12,161 INFO  mapred.LocalJobRunner (LocalJobRunner.java:run(325)) - Finishing task: attempt_local514605566_0014_r_000000_0
2015-02-11 00:27:12,161 INFO  mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2015-02-11 00:27:12,185 INFO  util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output/hadoop2-mr1/appliedassertionsplatform/value/pass/_temporary
2015-02-11 00:27:12,216 INFO  mapred.FileInputFormat (FileInputFormat.java:listStatus(247)) - Total input paths to process : 1
2015-02-11 00:27:12,218 INFO  cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/84ab5c9b70b89230/apache-2.5.x/build/test/output//hadoop2-mr1/appliedassertionsplatform/value/pass