2013-11-20 14:28:45,958 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2013-11-20 14:28:45,982 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop
2013-11-20 14:28:45,982 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.operation.assertion.AppliedAssertionsPlatformTest
2013-11-20 14:28:46,017 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(112)) - not using cluster
2013-11-20 14:28:46,383 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-11-20 14:28:46,386 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/artifacts-24/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-11-20 14:28:46,400 INFO property.AppProps (AppProps.java:getAppID(162)) - using app.id: 6E0EB8DFC1DF4084A39D70C65ACE1111
2013-11-20 14:28:46,610 INFO util.Version (Version.java:printBanner(78)) - Concurrent, Inc - Cascading 2.2.0
2013-11-20 14:28:46,613 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting
2013-11-20 14:28:46,614 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:46,614 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/NONE/STRICT"]
2013-11-20 14:28:46,614 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] parallel execution is enabled: false
2013-11-20 14:28:46,615 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting jobs: 1
2013-11-20 14:28:46,615 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] allocating threads: 1
2013-11-20 14:28:46,616 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] starting step: (1/1) ...latform/value/NONE/STRICT
2013-11-20 14:28:46,660 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2013-11-20 14:28:46,729 WARN snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2013-11-20 14:28:46,736 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:46,943 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] submitted hadoop job: job_local641499362_0001
2013-11-20 14:28:46,976 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-11-20 14:28:46,979 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local641499362_0001_m_000000_0
2013-11-20 14:28:47,034 INFO util.ProcessTree (ProcessTree.java:isSetsidSupported(63)) - setsid exited with exit code 0
2013-11-20 14:28:47,042 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@7458e2a1
2013-11-20 14:28:47,050 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt
2013-11-20 14:28:47,051 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@18f63055
2013-11-20 14:28:47,058 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-11-20 14:28:47,066 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-11-20 14:28:47,207 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-11-20 14:28:47,208 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-11-20 14:28:47,228 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-11-20 14:28:47,229 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-11-20 14:28:47,297 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:47,297 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:47,312 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-11-20 14:28:47,324 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-11-20 14:28:47,327 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local641499362_0001_m_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:47,334 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2013-11-20 14:28:47,334 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local641499362_0001_m_000000_0' done.
2013-11-20 14:28:47,335 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local641499362_0001_m_000000_0
2013-11-20 14:28:47,335 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-11-20 14:28:47,347 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@5e76f2e8
2013-11-20 14:28:47,348 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:47,354 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-11-20 14:28:47,361 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2013-11-20 14:28:47,362 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:47,364 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-11-20 14:28:47,364 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-11-20 14:28:47,384 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:47,385 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/NONE/STRICT"]
2013-11-20 14:28:47,403 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local641499362_0001_r_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:47,405 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:47,405 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local641499362_0001_r_000000_0 is allowed to commit now
2013-11-20 14:28:47,409 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local641499362_0001_r_000000_0' to file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/NONE/STRICT
2013-11-20 14:28:47,411 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-11-20 14:28:47,411 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local641499362_0001_r_000000_0' done.
2013-11-20 14:28:47,424 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/NONE/STRICT/_temporary
2013-11-20 14:28:47,446 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:47,469 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-11-20 14:28:47,469 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/artifacts-24/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-11-20 14:28:47,501 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting
2013-11-20 14:28:47,502 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:47,503 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/VALID/STRICT"]
2013-11-20 14:28:47,504 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] parallel execution is enabled: false
2013-11-20 14:28:47,504 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting jobs: 1
2013-11-20 14:28:47,505 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] allocating threads: 1
2013-11-20 14:28:47,506 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] starting step: (1/1) ...atform/value/VALID/STRICT
2013-11-20 14:28:47,523 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:47,622 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] submitted hadoop job: job_local529911888_0002
2013-11-20 14:28:47,625 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-11-20 14:28:47,625 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local529911888_0002_m_000000_0
2013-11-20 14:28:47,629 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@2e6f947b
2013-11-20 14:28:47,631 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt
2013-11-20 14:28:47,631 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@815a3a1
2013-11-20 14:28:47,633 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-11-20 14:28:47,633 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-11-20 14:28:47,759 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-11-20 14:28:47,760 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-11-20 14:28:47,761 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-11-20 14:28:47,762 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-11-20 14:28:47,775 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:47,776 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:47,781 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-11-20 14:28:47,784 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-11-20 14:28:47,786 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local529911888_0002_m_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:47,789 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2013-11-20 14:28:47,789 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local529911888_0002_m_000000_0' done.
2013-11-20 14:28:47,789 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local529911888_0002_m_000000_0
2013-11-20 14:28:47,790 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-11-20 14:28:47,794 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@4d2f9924
2013-11-20 14:28:47,795 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:47,795 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-11-20 14:28:47,796 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2013-11-20 14:28:47,797 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:47,797 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-11-20 14:28:47,797 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-11-20 14:28:47,808 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:47,808 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/VALID/STRICT"]
2013-11-20 14:28:47,816 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local529911888_0002_r_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:47,817 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:47,818 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local529911888_0002_r_000000_0 is allowed to commit now
2013-11-20 14:28:47,821 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local529911888_0002_r_000000_0' to file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/VALID/STRICT
2013-11-20 14:28:47,823 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-11-20 14:28:47,823 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local529911888_0002_r_000000_0' done.
2013-11-20 14:28:47,838 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/VALID/STRICT/_temporary
2013-11-20 14:28:47,864 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:47,886 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-11-20 14:28:47,886 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/artifacts-24/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-11-20 14:28:47,918 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting
2013-11-20 14:28:47,919 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:47,919 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/STRICT/STRICT"]
2013-11-20 14:28:47,919 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] parallel execution is enabled: false
2013-11-20 14:28:47,919 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting jobs: 1
2013-11-20 14:28:47,919 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] allocating threads: 1
2013-11-20 14:28:47,920 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] starting step: (1/1) ...tform/value/STRICT/STRICT
2013-11-20 14:28:47,935 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:47,986 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] submitted hadoop job: job_local488200862_0003
2013-11-20 14:28:47,990 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-11-20 14:28:47,990 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local488200862_0003_m_000000_0
2013-11-20 14:28:47,993 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@3e5646a5
2013-11-20 14:28:47,996 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt
2013-11-20 14:28:47,997 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@4805e9f1
2013-11-20 14:28:47,999 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-11-20 14:28:48,000 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-11-20 14:28:48,125 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-11-20 14:28:48,126 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-11-20 14:28:48,128 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-11-20 14:28:48,128 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-11-20 14:28:48,144 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:48,145 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:48,151 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-11-20 14:28:48,154 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-11-20 14:28:48,157 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local488200862_0003_m_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:48,160 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2013-11-20 14:28:48,161 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local488200862_0003_m_000000_0' done.
2013-11-20 14:28:48,161 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local488200862_0003_m_000000_0
2013-11-20 14:28:48,162 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-11-20 14:28:48,166 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@399197b
2013-11-20 14:28:48,167 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:48,168 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-11-20 14:28:48,168 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2013-11-20 14:28:48,170 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:48,170 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-11-20 14:28:48,172 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-11-20 14:28:48,184 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:48,185 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/STRICT/STRICT"]
2013-11-20 14:28:48,194 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:72)
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:119)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:107)
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:90)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:133)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2013-11-20 14:28:48,203 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:72)
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:119)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:107)
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:90)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:133)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2013-11-20 14:28:48,212 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(435)) - job_local488200862_0003
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:72)
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:119)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:107)
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:90)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:133)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2013-11-20 14:28:48,221 WARN flow.FlowStep (BaseFlowStep.java:logWarn(747)) - [test] task completion events identify failed tasks
2013-11-20 14:28:48,221 WARN flow.FlowStep (BaseFlowStep.java:logWarn(747)) - [test] task completion events count: 0
2013-11-20 14:28:48,223 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] stopping all jobs
2013-11-20 14:28:48,223 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] stopping: (1/1) ...tform/value/STRICT/STRICT
2013-11-20 14:28:48,223 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] stopped all jobs
2013-11-20 14:28:48,224 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/STRICT/STRICT/_temporary
2013-11-20 14:28:48,237 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-11-20 14:28:48,237 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/artifacts-24/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-11-20 14:28:48,264 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting
2013-11-20 14:28:48,265 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:48,265 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/NONE/VALID"]
2013-11-20 14:28:48,265 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] parallel execution is enabled: false
2013-11-20 14:28:48,265 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting jobs: 1
2013-11-20 14:28:48,265 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] allocating threads: 1
2013-11-20 14:28:48,266 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] starting step: (1/1) ...platform/value/NONE/VALID
2013-11-20 14:28:48,281 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:48,318 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] submitted hadoop job: job_local1651046801_0004
2013-11-20 14:28:48,321 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-11-20 14:28:48,322 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local1651046801_0004_m_000000_0
2013-11-20 14:28:48,324 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@549ad840
2013-11-20 14:28:48,327 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt
2013-11-20 14:28:48,328 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@4d0ac2a3
2013-11-20 14:28:48,330 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-11-20 14:28:48,330 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-11-20 14:28:48,449 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-11-20 14:28:48,450 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-11-20 14:28:48,452 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-11-20 14:28:48,453 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-11-20 14:28:48,464 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:48,464 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:48,470 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-11-20 14:28:48,473 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-11-20 14:28:48,487 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1651046801_0004_m_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:48,490 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2013-11-20 14:28:48,490 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1651046801_0004_m_000000_0' done.
2013-11-20 14:28:48,491 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local1651046801_0004_m_000000_0
2013-11-20 14:28:48,491 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-11-20 14:28:48,496 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@67673a2
2013-11-20 14:28:48,498 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:48,499 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-11-20 14:28:48,500 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2013-11-20 14:28:48,501 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:48,501 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-11-20 14:28:48,502 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-11-20 14:28:48,511 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:48,512 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/NONE/VALID"]
2013-11-20 14:28:48,520 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1651046801_0004_r_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:48,522 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:48,523 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local1651046801_0004_r_000000_0 is allowed to commit now
2013-11-20 14:28:48,526 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local1651046801_0004_r_000000_0' to file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/NONE/VALID
2013-11-20 14:28:48,528 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-11-20 14:28:48,528 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1651046801_0004_r_000000_0' done.
2013-11-20 14:28:48,538 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/NONE/VALID/_temporary
2013-11-20 14:28:48,550 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:48,563 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-11-20 14:28:48,564 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/artifacts-24/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-11-20 14:28:48,590 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting
2013-11-20 14:28:48,591 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:48,591 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/VALID/VALID"]
2013-11-20 14:28:48,591 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] parallel execution is enabled: false
2013-11-20 14:28:48,591 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting jobs: 1
2013-11-20 14:28:48,591 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] allocating threads: 1
2013-11-20 14:28:48,592 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] starting step: (1/1) ...latform/value/VALID/VALID
2013-11-20 14:28:48,605 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:48,641 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] submitted hadoop job: job_local2138109479_0005
2013-11-20 14:28:48,645 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-11-20 14:28:48,645 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local2138109479_0005_m_000000_0
2013-11-20 14:28:48,647 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@5585c0de
2013-11-20 14:28:48,648 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt
2013-11-20 14:28:48,648 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@16a99013
2013-11-20 14:28:48,651 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-11-20 14:28:48,652 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-11-20 14:28:48,768 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-11-20 14:28:48,769 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-11-20 14:28:48,770 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-11-20 14:28:48,770 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-11-20 14:28:48,783 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:48,783 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:48,788 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-11-20 14:28:48,791 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-11-20 14:28:48,793 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local2138109479_0005_m_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:48,796 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2013-11-20 14:28:48,796 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local2138109479_0005_m_000000_0' done.
2013-11-20 14:28:48,796 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local2138109479_0005_m_000000_0
2013-11-20 14:28:48,797 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-11-20 14:28:48,801 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@28caea19
2013-11-20 14:28:48,802 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:48,803 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-11-20 14:28:48,804 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2013-11-20 14:28:48,805 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:48,806 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-11-20 14:28:48,806 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-11-20 14:28:48,816 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:48,817 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/VALID/VALID"]
2013-11-20 14:28:48,824 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:72)
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:119)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:107)
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:90)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:133)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2013-11-20 14:28:48,831 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:72)
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:119)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:107)
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:90)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:133)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2013-11-20 14:28:48,838 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(435)) - job_local2138109479_0005
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:72)
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:119)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:107)
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:90)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:133)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2013-11-20 14:28:48,844 WARN flow.FlowStep (BaseFlowStep.java:logWarn(747)) - [test] task completion events identify failed tasks
2013-11-20 14:28:48,844 WARN flow.FlowStep (BaseFlowStep.java:logWarn(747)) - [test] task completion events count: 0
2013-11-20 14:28:48,846 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] stopping all jobs
2013-11-20 14:28:48,846 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] stopping: (1/1) ...latform/value/VALID/VALID
2013-11-20 14:28:48,846 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] stopped all jobs
2013-11-20 14:28:48,847 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/VALID/VALID/_temporary
2013-11-20 14:28:48,847 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/value/VALID/VALID
2013-11-20 14:28:48,847 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/value/VALID/STRICT
2013-11-20 14:28:48,848 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/value/NONE/VALID
2013-11-20 14:28:48,848 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/value/NONE/STRICT
2013-11-20 14:28:48,848 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/value/STRICT/STRICT
2013-11-20 14:28:48,863 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-11-20 14:28:48,864 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/artifacts-24/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-11-20 14:28:48,889 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting
2013-11-20 14:28:48,889 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:48,890 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/NONE/STRICT"]
2013-11-20 14:28:48,890 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] parallel execution is enabled: false
2013-11-20 14:28:48,890 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting jobs: 1
2013-11-20 14:28:48,890 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] allocating threads: 1
2013-11-20 14:28:48,891 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] starting step: (1/1) ...latform/group/NONE/STRICT
2013-11-20 14:28:48,905 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:48,942 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] submitted hadoop job: job_local1950748376_0006
2013-11-20 14:28:48,945 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-11-20 14:28:48,945 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local1950748376_0006_m_000000_0
2013-11-20 14:28:48,947 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@2c8f3eac
2013-11-20 14:28:48,948 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt
2013-11-20 14:28:48,949 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@1d1126f6
2013-11-20 14:28:48,950 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-11-20 14:28:48,951 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-11-20 14:28:49,284 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-11-20 14:28:49,284 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-11-20 14:28:49,286 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-11-20 14:28:49,286 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-11-20 14:28:49,296 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:49,296 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:49,300 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-11-20 14:28:49,303 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-11-20 14:28:49,305 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1950748376_0006_m_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:49,308 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2013-11-20 14:28:49,308 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1950748376_0006_m_000000_0' done.
2013-11-20 14:28:49,308 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local1950748376_0006_m_000000_0
2013-11-20 14:28:49,308 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-11-20 14:28:49,312 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@48834af6
2013-11-20 14:28:49,313 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:49,314 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-11-20 14:28:49,314 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2013-11-20 14:28:49,315 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:49,315 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-11-20 14:28:49,315 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-11-20 14:28:49,323 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:49,324 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/NONE/STRICT"]
2013-11-20 14:28:49,333 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1950748376_0006_r_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:49,335 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:49,335 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local1950748376_0006_r_000000_0 is allowed to commit now
2013-11-20 14:28:49,338 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local1950748376_0006_r_000000_0' to file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/NONE/STRICT
2013-11-20 14:28:49,340 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-11-20 14:28:49,340 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1950748376_0006_r_000000_0' done.
2013-11-20 14:28:49,351 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/NONE/STRICT/_temporary
2013-11-20 14:28:49,362 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:49,374 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-11-20 14:28:49,375 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/artifacts-24/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-11-20 14:28:49,398 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting
2013-11-20 14:28:49,398 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:49,398 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/VALID/STRICT"]
2013-11-20 14:28:49,399 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] parallel execution is enabled: false
2013-11-20 14:28:49,399 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting jobs: 1
2013-11-20 14:28:49,399 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] allocating threads: 1
2013-11-20 14:28:49,400 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] starting step: (1/1) ...atform/group/VALID/STRICT
2013-11-20 14:28:49,412 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:49,444 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] submitted hadoop job: job_local269372058_0007
2013-11-20 14:28:49,448 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-11-20 14:28:49,448 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local269372058_0007_m_000000_0
2013-11-20 14:28:49,450 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@215a3a92
2013-11-20 14:28:49,452 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt
2013-11-20 14:28:49,452 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@4ad38c3d
2013-11-20 14:28:49,454 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-11-20 14:28:49,455 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-11-20 14:28:49,580 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-11-20 14:28:49,581 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-11-20 14:28:49,583 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-11-20 14:28:49,583 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-11-20 14:28:49,592 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:49,593 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:49,597 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-11-20 14:28:49,600 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-11-20 14:28:49,603 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local269372058_0007_m_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:49,605 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2013-11-20 14:28:49,606 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local269372058_0007_m_000000_0' done.
2013-11-20 14:28:49,606 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local269372058_0007_m_000000_0
2013-11-20 14:28:49,607 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-11-20 14:28:49,611 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@28b7f2d0
2013-11-20 14:28:49,612 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:49,613 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-11-20 14:28:49,613 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2013-11-20 14:28:49,613 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:49,614 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-11-20 14:28:49,614 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-11-20 14:28:49,622 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:49,622 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/VALID/STRICT"]
2013-11-20 14:28:49,628 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local269372058_0007_r_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:49,630 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:49,630 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local269372058_0007_r_000000_0 is allowed to commit now
2013-11-20 14:28:49,633 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local269372058_0007_r_000000_0' to file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/VALID/STRICT
2013-11-20 14:28:49,634 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-11-20 14:28:49,635 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local269372058_0007_r_000000_0' done.
2013-11-20 14:28:49,653 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/VALID/STRICT/_temporary
2013-11-20 14:28:49,663 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:49,675 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-11-20 14:28:49,675 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/artifacts-24/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-11-20 14:28:49,700 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting
2013-11-20 14:28:49,701 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:49,701 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/STRICT/STRICT"]
2013-11-20 14:28:49,701 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] parallel execution is enabled: false
2013-11-20 14:28:49,701 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting jobs: 1
2013-11-20 14:28:49,702 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] allocating threads: 1
2013-11-20 14:28:49,703 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] starting step: (1/1) ...tform/group/STRICT/STRICT
2013-11-20 14:28:49,716 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:49,746 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] submitted hadoop job: job_local2002202785_0008
2013-11-20 14:28:49,751 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-11-20 14:28:49,751 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local2002202785_0008_m_000000_0
2013-11-20 14:28:49,754 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@60223be4
2013-11-20 14:28:49,756 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt
2013-11-20 14:28:49,756 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@24ae2d66
2013-11-20 14:28:49,758 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-11-20 14:28:49,759 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-11-20 14:28:49,881 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-11-20 14:28:49,882 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-11-20 14:28:49,884 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-11-20 14:28:49,884 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-11-20 14:28:49,894 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:49,895 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:49,899 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-11-20 14:28:49,902 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-11-20 14:28:49,904 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local2002202785_0008_m_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:49,907 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2013-11-20 14:28:49,907 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local2002202785_0008_m_000000_0' done.
2013-11-20 14:28:49,908 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local2002202785_0008_m_000000_0
2013-11-20 14:28:49,908 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-11-20 14:28:49,913 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@78c70f32
2013-11-20 14:28:49,913 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:49,914 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-11-20 14:28:49,915 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2013-11-20 14:28:49,915 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:49,916 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-11-20 14:28:49,916 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-11-20 14:28:49,925 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:49,925 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/STRICT/STRICT"]
2013-11-20 14:28:49,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:167)
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:119)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:107)
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:90)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:133)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2013-11-20 14:28:49,933 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:167)
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:119)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:107)
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:90)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:133)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2013-11-20 14:28:49,935 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(435)) - job_local2002202785_0008
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:167)
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:119)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:107)
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:90)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:133)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2013-11-20 14:28:49,939 WARN flow.FlowStep (BaseFlowStep.java:logWarn(747)) - [test] task completion events identify failed tasks
2013-11-20 14:28:49,940 WARN flow.FlowStep (BaseFlowStep.java:logWarn(747)) - [test] task completion events count: 0
2013-11-20 14:28:49,943 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] stopping all jobs
2013-11-20 14:28:49,943 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] stopping: (1/1) ...tform/group/STRICT/STRICT
2013-11-20 14:28:49,944 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] stopped all jobs
2013-11-20 14:28:49,944 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] shutting down job executor
2013-11-20 14:28:49,944 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] shutdown complete
2013-11-20 14:28:49,945 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/STRICT/STRICT/_temporary
2013-11-20 14:28:49,956 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-11-20 14:28:49,957 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/artifacts-24/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-11-20 14:28:49,981 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting
2013-11-20 14:28:49,982 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:49,982 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/NONE/VALID"]
2013-11-20 14:28:49,983 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] parallel execution is enabled: false
2013-11-20 14:28:49,983 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting jobs: 1
2013-11-20 14:28:49,983 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] allocating threads: 1
2013-11-20 14:28:49,985 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] starting step: (1/1) ...platform/group/NONE/VALID
2013-11-20 14:28:49,998 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:50,032 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] submitted hadoop job: job_local233460426_0009
2013-11-20 14:28:50,036 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-11-20 14:28:50,036 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local233460426_0009_m_000000_0
2013-11-20 14:28:50,038 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@5e4f12c2
2013-11-20 14:28:50,040 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt
2013-11-20 14:28:50,040 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@3bf0d7f5
2013-11-20 14:28:50,041 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-11-20 14:28:50,042 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-11-20 14:28:50,161 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-11-20 14:28:50,161 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-11-20 14:28:50,163 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-11-20 14:28:50,163 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-11-20 14:28:50,172 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:50,172 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:50,176 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-11-20 14:28:50,179 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-11-20 14:28:50,181 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local233460426_0009_m_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:50,184 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2013-11-20 14:28:50,184 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local233460426_0009_m_000000_0' done.
2013-11-20 14:28:50,184 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local233460426_0009_m_000000_0
2013-11-20 14:28:50,186 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-11-20 14:28:50,191 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@5306989e
2013-11-20 14:28:50,191 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:50,192 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-11-20 14:28:50,193 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2013-11-20 14:28:50,194 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:50,194 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-11-20 14:28:50,194 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-11-20 14:28:50,203 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:50,204 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/NONE/VALID"]
2013-11-20 14:28:50,212 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local233460426_0009_r_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:50,214 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:50,214 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local233460426_0009_r_000000_0 is allowed to commit now
2013-11-20 14:28:50,218 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local233460426_0009_r_000000_0' to file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/NONE/VALID
2013-11-20 14:28:50,219 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-11-20 14:28:50,219 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local233460426_0009_r_000000_0' done.
2013-11-20 14:28:50,230 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/NONE/VALID/_temporary
2013-11-20 14:28:50,242 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:50,254 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-11-20 14:28:50,255 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/artifacts-24/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-11-20 14:28:50,297 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting
2013-11-20 14:28:50,297 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:50,297 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/VALID/VALID"]
2013-11-20 14:28:50,299 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] parallel execution is enabled: false
2013-11-20 14:28:50,300 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting jobs: 1
2013-11-20 14:28:50,300 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] allocating threads: 1
2013-11-20 14:28:50,301 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] starting step: (1/1) ...latform/group/VALID/VALID
2013-11-20 14:28:50,313 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:50,342 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] submitted hadoop job: job_local176299819_0010
2013-11-20 14:28:50,346 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-11-20 14:28:50,346 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local176299819_0010_m_000000_0
2013-11-20 14:28:50,348 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@1c6250d2
2013-11-20 14:28:50,350 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt
2013-11-20 14:28:50,350 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@10469e8
2013-11-20 14:28:50,351 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-11-20 14:28:50,352 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-11-20 14:28:50,479 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-11-20 14:28:50,479 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-11-20 14:28:50,480 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-11-20 14:28:50,481 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-11-20 14:28:50,489 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:50,490 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:50,493 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-11-20 14:28:50,496 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-11-20 14:28:50,498 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local176299819_0010_m_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:50,500 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2013-11-20 14:28:50,501 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local176299819_0010_m_000000_0' done.
2013-11-20 14:28:50,501 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local176299819_0010_m_000000_0
2013-11-20 14:28:50,501 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-11-20 14:28:50,506 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@6350ed68
2013-11-20 14:28:50,507 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:50,508 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-11-20 14:28:50,509 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2013-11-20 14:28:50,509 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:50,510 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-11-20 14:28:50,510 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-11-20 14:28:50,520 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:50,520 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/VALID/VALID"]
2013-11-20 14:28:50,527 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:167)
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:119)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:107)
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:90)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:133)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2013-11-20 14:28:50,532 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:167)
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:119)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:107)
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:90)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:133)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2013-11-20 14:28:50,539 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(435)) - job_local176299819_0010
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:167)
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:119)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:107)
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:90)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:133)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2013-11-20 14:28:50,544 WARN flow.FlowStep (BaseFlowStep.java:logWarn(747)) - [test] task completion events identify failed tasks
2013-11-20 14:28:50,545 WARN flow.FlowStep (BaseFlowStep.java:logWarn(747)) - [test] task completion events count: 0
2013-11-20 14:28:50,548 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] stopping all jobs
2013-11-20 14:28:50,548 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] stopping: (1/1) ...latform/group/VALID/VALID
2013-11-20 14:28:50,548 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] stopped all jobs
2013-11-20 14:28:50,549 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/VALID/VALID/_temporary
2013-11-20 14:28:50,549 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/group/NONE/VALID
2013-11-20 14:28:50,550 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/group/VALID/STRICT
2013-11-20 14:28:50,550 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/group/STRICT/STRICT
2013-11-20 14:28:50,550 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/group/NONE/STRICT
2013-11-20 14:28:50,551 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/group/VALID/VALID
2013-11-20 14:28:50,562 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-11-20 14:28:50,563 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/artifacts-24/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-11-20 14:28:50,583 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting
2013-11-20 14:28:50,583 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:50,584 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/fail"]
2013-11-20 14:28:50,585 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] parallel execution is enabled: false
2013-11-20 14:28:50,585 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting jobs: 1
2013-11-20 14:28:50,585 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] allocating threads: 1
2013-11-20 14:28:50,586 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] starting step: (1/1) ...edassertionsplatform/fail
2013-11-20 14:28:50,597 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:50,623 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] submitted hadoop job: job_local1492634703_0011
2013-11-20 14:28:50,627 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-11-20 14:28:50,627 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local1492634703_0011_m_000000_0
2013-11-20 14:28:50,630 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@7ef72e77
2013-11-20 14:28:50,631 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt
2013-11-20 14:28:50,632 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@a868c6d
2013-11-20 14:28:50,633 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-11-20 14:28:50,634 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-11-20 14:28:50,713 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-11-20 14:28:50,717 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-11-20 14:28:50,719 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-11-20 14:28:50,720 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-11-20 14:28:50,729 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:50,730 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:50,734 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-11-20 14:28:50,737 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-11-20 14:28:50,739 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1492634703_0011_m_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:50,742 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2013-11-20 14:28:50,742 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1492634703_0011_m_000000_0' done.
2013-11-20 14:28:50,742 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local1492634703_0011_m_000000_0
2013-11-20 14:28:50,743 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-11-20 14:28:50,759 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@3590ed52
2013-11-20 14:28:50,759 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:50,761 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-11-20 14:28:50,762 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2013-11-20 14:28:50,763 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:50,764 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-11-20 14:28:50,764 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-11-20 14:28:50,772 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:50,772 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/fail"]
2013-11-20 14:28:50,777 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:167)
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:119)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:107)
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:90)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:133)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2013-11-20 14:28:50,778 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:167)
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:119)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:107)
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:90)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:133)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2013-11-20 14:28:50,780 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(435)) - job_local1492634703_0011
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:167)
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:119)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:107)
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:90)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:133)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2013-11-20 14:28:50,786 WARN flow.FlowStep (BaseFlowStep.java:logWarn(747)) - [test] task completion events identify failed tasks
2013-11-20 14:28:50,786 WARN flow.FlowStep (BaseFlowStep.java:logWarn(747)) - [test] task completion events count: 0
2013-11-20 14:28:50,788 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] stopping all jobs
2013-11-20 14:28:50,788 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] stopping: (1/1) ...edassertionsplatform/fail
2013-11-20 14:28:50,788 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] stopped all jobs
2013-11-20 14:28:50,789 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/fail/_temporary
2013-11-20 14:28:50,789 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/fail
2013-11-20 14:28:50,800 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-11-20 14:28:50,801 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/artifacts-24/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-11-20 14:28:50,818 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting
2013-11-20 14:28:50,819 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:50,820 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/pass"]
2013-11-20 14:28:50,821 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] parallel execution is enabled: false
2013-11-20 14:28:50,821 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting jobs: 1
2013-11-20 14:28:50,821 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] allocating threads: 1
2013-11-20 14:28:50,823 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] starting step: (1/1) ...edassertionsplatform/pass
2013-11-20 14:28:50,834 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:50,858 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] submitted hadoop job: job_local575395211_0012
2013-11-20 14:28:50,861 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-11-20 14:28:50,862 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local575395211_0012_m_000000_0
2013-11-20 14:28:50,863 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@31fc6b2
2013-11-20 14:28:50,865 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt
2013-11-20 14:28:50,865 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@1ee83c97
2013-11-20 14:28:50,866 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-11-20 14:28:50,866 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-11-20 14:28:51,157 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-11-20 14:28:51,157 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-11-20 14:28:51,158 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-11-20 14:28:51,158 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-11-20 14:28:51,166 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:51,167 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:51,170 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-11-20 14:28:51,173 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-11-20 14:28:51,175 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local575395211_0012_m_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:51,177 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2013-11-20 14:28:51,177 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local575395211_0012_m_000000_0' done.
2013-11-20 14:28:51,177 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local575395211_0012_m_000000_0
2013-11-20 14:28:51,178 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-11-20 14:28:51,182 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@237360be
2013-11-20 14:28:51,182 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:51,183 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-11-20 14:28:51,184 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2013-11-20 14:28:51,184 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:51,184 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-11-20 14:28:51,185 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-11-20 14:28:51,192 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:51,193 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/pass"]
2013-11-20 14:28:51,198 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local575395211_0012_r_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:51,200 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:51,200 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local575395211_0012_r_000000_0 is allowed to commit now
2013-11-20 14:28:51,203 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local575395211_0012_r_000000_0' to file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/pass
2013-11-20 14:28:51,204 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-11-20 14:28:51,205 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local575395211_0012_r_000000_0' done.
2013-11-20 14:28:51,218 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/pass/_temporary
2013-11-20 14:28:51,229 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:51,231 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/pass
2013-11-20 14:28:51,242 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-11-20 14:28:51,242 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/artifacts-24/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-11-20 14:28:51,261 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting
2013-11-20 14:28:51,261 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:51,262 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/fail"]
2013-11-20 14:28:51,262 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] parallel execution is enabled: false
2013-11-20 14:28:51,262 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting jobs: 1
2013-11-20 14:28:51,263 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] allocating threads: 1
2013-11-20 14:28:51,264 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] starting step: (1/1) ...rtionsplatform/value/fail
2013-11-20 14:28:51,282 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:51,308 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] submitted hadoop job: job_local1324294441_0013
2013-11-20 14:28:51,312 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-11-20 14:28:51,312 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local1324294441_0013_m_000000_0
2013-11-20 14:28:51,314 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@4d687dcd
2013-11-20 14:28:51,315 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt
2013-11-20 14:28:51,315 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@327800e9
2013-11-20 14:28:51,317 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-11-20 14:28:51,317 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-11-20 14:28:51,398 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-11-20 14:28:51,398 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-11-20 14:28:51,399 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-11-20 14:28:51,400 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-11-20 14:28:51,407 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:51,407 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:51,410 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-11-20 14:28:51,412 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-11-20 14:28:51,414 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1324294441_0013_m_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:51,417 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2013-11-20 14:28:51,417 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1324294441_0013_m_000000_0' done.
2013-11-20 14:28:51,417 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local1324294441_0013_m_000000_0
2013-11-20 14:28:51,418 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-11-20 14:28:51,421 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@64fb7efa
2013-11-20 14:28:51,422 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:51,423 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-11-20 14:28:51,423 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2013-11-20 14:28:51,423 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:51,424 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-11-20 14:28:51,424 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-11-20 14:28:51,431 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:51,431 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/fail"]
2013-11-20 14:28:51,437 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:72)
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:119)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:107)
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:90)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:133)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2013-11-20 14:28:51,438 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:72)
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:119)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:107)
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:90)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:133)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2013-11-20 14:28:51,440 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(435)) - job_local1324294441_0013
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:72)
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:119)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:107)
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:90)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:133)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2013-11-20 14:28:51,442 WARN flow.FlowStep (BaseFlowStep.java:logWarn(747)) - [test] task completion events identify failed tasks
2013-11-20 14:28:51,442 WARN flow.FlowStep (BaseFlowStep.java:logWarn(747)) - [test] task completion events count: 0
2013-11-20 14:28:51,443 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] stopping all jobs
2013-11-20 14:28:51,444 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] stopping: (1/1) ...rtionsplatform/value/fail
2013-11-20 14:28:51,444 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] stopped all jobs
2013-11-20 14:28:51,445 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/fail/_temporary
2013-11-20 14:28:51,445 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/value/fail
2013-11-20 14:28:51,457 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(319)) - using default application jar, may cause class not found exceptions on the cluster
2013-11-20 14:28:51,458 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(203)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/artifacts-24/filestore/cascading/cascading-hadoop/2.2.0/jar/c7b52bd4c6da523ebde0a5d6eca2475123783db2/cascading-hadoop-2.2.0.jar
2013-11-20 14:28:51,475 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting
2013-11-20 14:28:51,476 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:51,476 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/pass"]
2013-11-20 14:28:51,477 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] parallel execution is enabled: false
2013-11-20 14:28:51,477 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] starting jobs: 1
2013-11-20 14:28:51,477 INFO flow.Flow (BaseFlow.java:logInfo(1306)) - [test] allocating threads: 1
2013-11-20 14:28:51,478 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] starting step: (1/1) ...rtionsplatform/value/pass
2013-11-20 14:28:51,493 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:51,524 INFO flow.FlowStep (BaseFlowStep.java:logInfo(742)) - [test] submitted hadoop job: job_local183455767_0014
2013-11-20 14:28:51,527 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2013-11-20 14:28:51,528 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local183455767_0014_m_000000_0
2013-11-20 14:28:51,529 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@3ed9c921
2013-11-20 14:28:51,530 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt
2013-11-20 14:28:51,531 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@bebf1eb
2013-11-20 14:28:51,532 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2013-11-20 14:28:51,532 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2013-11-20 14:28:51,659 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2013-11-20 14:28:51,659 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2013-11-20 14:28:51,661 INFO hadoop.FlowMapper (FlowMapper.java:configure(70)) - cascading version: 2.2.0
2013-11-20 14:28:51,661 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - child jvm opts: -Xmx200m
2013-11-20 14:28:51,668 INFO hadoop.FlowMapper (FlowMapper.java:configure(86)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2013-11-20 14:28:51,669 INFO hadoop.FlowMapper (FlowMapper.java:configure(89)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:51,672 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2013-11-20 14:28:51,675 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2013-11-20 14:28:51,676 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local183455767_0014_m_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:51,679 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2013-11-20 14:28:51,679 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local183455767_0014_m_000000_0' done.
2013-11-20 14:28:51,679 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local183455767_0014_m_000000_0
2013-11-20 14:28:51,679 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2013-11-20 14:28:51,683 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@6221a86a
2013-11-20 14:28:51,684 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:51,685 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2013-11-20 14:28:51,685 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2013-11-20 14:28:51,686 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:51,686 INFO hadoop.FlowReducer (FlowReducer.java:configure(77)) - cascading version: 2.2.0
2013-11-20 14:28:51,686 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - child jvm opts: -Xmx200m
2013-11-20 14:28:51,693 INFO hadoop.FlowReducer (FlowReducer.java:configure(96)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2013-11-20 14:28:51,693 INFO hadoop.FlowReducer (FlowReducer.java:configure(99)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/pass"]
2013-11-20 14:28:51,699 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local183455767_0014_r_000000_0 is done. And is in the process of commiting
2013-11-20 14:28:51,700 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2013-11-20 14:28:51,700 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local183455767_0014_r_000000_0 is allowed to commit now
2013-11-20 14:28:51,703 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local183455767_0014_r_000000_0' to file:/opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/pass
2013-11-20 14:28:51,704 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2013-11-20 14:28:51,705 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local183455767_0014_r_000000_0' done.
2013-11-20 14:28:51,719 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/pass/_temporary
2013-11-20 14:28:51,729 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2013-11-20 14:28:51,731 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/d1f96f51023738a5/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/value/pass