2014-08-22 17:55:41,020 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2014-08-22 17:55:41,068 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop
2014-08-22 17:55:41,069 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.operation.assertion.AppliedAssertionsPlatformTest
2014-08-22 17:55:41,109 INFO hadoop.HadoopPlatform (HadoopPlatform.java:setUp(112)) - not using cluster
2014-08-22 17:55:41,518 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 17:55:41,521 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 17:55:41,534 INFO property.AppProps (AppProps.java:getAppID(162)) - using app.id: EE9812CE08F948D9B670865A58786C54
2014-08-22 17:55:41,774 INFO util.Version (Version.java:printBanner(78)) - Concurrent, Inc - Cascading 2.5.6
2014-08-22 17:55:41,776 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 17:55:41,777 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:41,778 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/NONE/STRICT"]
2014-08-22 17:55:41,778 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 17:55:41,778 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 17:55:41,779 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 17:55:41,780 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...latform/value/NONE/STRICT
2014-08-22 17:55:41,828 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(52)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2014-08-22 17:55:41,899 WARN snappy.LoadSnappy (LoadSnappy.java:<clinit>(46)) - Snappy native library not loaded
2014-08-22 17:55:41,903 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:42,156 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local961478360_0001
2014-08-22 17:55:42,157 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 17:55:42,191 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2014-08-22 17:55:42,194 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local961478360_0001_m_000000_0
2014-08-22 17:55:42,254 INFO util.ProcessTree (ProcessTree.java:isSetsidSupported(63)) - setsid exited with exit code 0
2014-08-22 17:55:42,263 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@5c1a1ff9
2014-08-22 17:55:42,277 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt
2014-08-22 17:55:42,277 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@151ff451
2014-08-22 17:55:42,285 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2014-08-22 17:55:42,294 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2014-08-22 17:55:42,436 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2014-08-22 17:55:42,437 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2014-08-22 17:55:42,459 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 17:55:42,459 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 17:55:42,532 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:42,533 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:42,550 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2014-08-22 17:55:42,563 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2014-08-22 17:55:42,566 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local961478360_0001_m_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:42,572 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2014-08-22 17:55:42,572 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local961478360_0001_m_000000_0' done.
2014-08-22 17:55:42,573 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local961478360_0001_m_000000_0
2014-08-22 17:55:42,573 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2014-08-22 17:55:42,585 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@7591777e
2014-08-22 17:55:42,586 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:42,591 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2014-08-22 17:55:42,598 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2014-08-22 17:55:42,599 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:42,600 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 17:55:42,600 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 17:55:42,622 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:42,622 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/NONE/STRICT"]
2014-08-22 17:55:42,644 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local961478360_0001_r_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:42,646 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:42,646 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local961478360_0001_r_000000_0 is allowed to commit now
2014-08-22 17:55:42,651 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local961478360_0001_r_000000_0' to file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/NONE/STRICT
2014-08-22 17:55:42,653 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2014-08-22 17:55:42,653 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local961478360_0001_r_000000_0' done.
2014-08-22 17:55:42,668 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/NONE/STRICT/_temporary
2014-08-22 17:55:42,693 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:42,720 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 17:55:42,721 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 17:55:42,760 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 17:55:42,760 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:42,761 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/VALID/STRICT"]
2014-08-22 17:55:42,762 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 17:55:42,762 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 17:55:42,762 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 17:55:42,763 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...atform/value/VALID/STRICT
2014-08-22 17:55:42,780 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:42,886 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1245179351_0002
2014-08-22 17:55:42,886 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 17:55:42,890 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2014-08-22 17:55:42,890 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local1245179351_0002_m_000000_0
2014-08-22 17:55:42,893 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@3435ec9
2014-08-22 17:55:42,895 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt
2014-08-22 17:55:42,896 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@20c62080
2014-08-22 17:55:42,898 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2014-08-22 17:55:42,898 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2014-08-22 17:55:43,044 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2014-08-22 17:55:43,044 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2014-08-22 17:55:43,046 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 17:55:43,046 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 17:55:43,064 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:43,065 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:43,071 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2014-08-22 17:55:43,075 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2014-08-22 17:55:43,077 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1245179351_0002_m_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:43,080 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2014-08-22 17:55:43,081 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1245179351_0002_m_000000_0' done.
2014-08-22 17:55:43,081 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local1245179351_0002_m_000000_0
2014-08-22 17:55:43,081 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2014-08-22 17:55:43,086 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@bba92db
2014-08-22 17:55:43,087 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:43,088 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2014-08-22 17:55:43,088 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2014-08-22 17:55:43,089 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:43,090 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 17:55:43,090 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 17:55:43,103 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:43,103 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/VALID/STRICT"]
2014-08-22 17:55:43,112 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1245179351_0002_r_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:43,114 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:43,114 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local1245179351_0002_r_000000_0 is allowed to commit now
2014-08-22 17:55:43,125 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local1245179351_0002_r_000000_0' to file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/VALID/STRICT
2014-08-22 17:55:43,126 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2014-08-22 17:55:43,127 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1245179351_0002_r_000000_0' done.
2014-08-22 17:55:43,143 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/VALID/STRICT/_temporary
2014-08-22 17:55:43,165 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:43,190 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 17:55:43,190 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 17:55:43,229 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 17:55:43,229 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:43,230 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/STRICT/STRICT"]
2014-08-22 17:55:43,230 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 17:55:43,230 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 17:55:43,230 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 17:55:43,231 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...tform/value/STRICT/STRICT
2014-08-22 17:55:43,248 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:43,303 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1404890956_0003
2014-08-22 17:55:43,304 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 17:55:43,309 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2014-08-22 17:55:43,309 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local1404890956_0003_m_000000_0
2014-08-22 17:55:43,311 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@4b94ba17
2014-08-22 17:55:43,313 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt
2014-08-22 17:55:43,313 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@1bfd9cd5
2014-08-22 17:55:43,315 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2014-08-22 17:55:43,316 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2014-08-22 17:55:43,448 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2014-08-22 17:55:43,448 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2014-08-22 17:55:43,449 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 17:55:43,450 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 17:55:43,465 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:43,465 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:43,472 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2014-08-22 17:55:43,475 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2014-08-22 17:55:43,478 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1404890956_0003_m_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:43,480 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2014-08-22 17:55:43,481 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1404890956_0003_m_000000_0' done.
2014-08-22 17:55:43,481 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local1404890956_0003_m_000000_0
2014-08-22 17:55:43,481 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2014-08-22 17:55:43,486 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@17a697a1
2014-08-22 17:55:43,487 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:43,488 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2014-08-22 17:55:43,489 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2014-08-22 17:55:43,489 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:43,490 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 17:55:43,490 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 17:55:43,504 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:43,504 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/STRICT/STRICT"]
2014-08-22 17:55:43,513 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:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2014-08-22 17:55:43,516 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:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2014-08-22 17:55:43,519 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(435)) - job_local1404890956_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:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2014-08-22 17:55:43,526 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local1404890956_0003 state at FAILED
2014-08-22 17:55:43,527 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2014-08-22 17:55:43,528 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2014-08-22 17:55:43,528 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2014-08-22 17:55:43,530 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] stopping all jobs
2014-08-22 17:55:43,530 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...tform/value/STRICT/STRICT
2014-08-22 17:55:43,530 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] stopped all jobs
2014-08-22 17:55:43,531 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/STRICT/STRICT/_temporary
2014-08-22 17:55:43,545 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 17:55:43,546 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 17:55:43,577 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 17:55:43,577 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:43,577 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/NONE/VALID"]
2014-08-22 17:55:43,578 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 17:55:43,578 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 17:55:43,578 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 17:55:43,579 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...platform/value/NONE/VALID
2014-08-22 17:55:43,596 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:43,643 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local213756489_0004
2014-08-22 17:55:43,643 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 17:55:43,646 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2014-08-22 17:55:43,646 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local213756489_0004_m_000000_0
2014-08-22 17:55:43,648 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@195b6aad
2014-08-22 17:55:43,650 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt
2014-08-22 17:55:43,650 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@67b14530
2014-08-22 17:55:43,652 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2014-08-22 17:55:43,652 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2014-08-22 17:55:43,796 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2014-08-22 17:55:43,796 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2014-08-22 17:55:43,798 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 17:55:43,799 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 17:55:43,813 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:43,813 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:43,820 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2014-08-22 17:55:43,824 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2014-08-22 17:55:43,826 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local213756489_0004_m_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:43,829 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2014-08-22 17:55:43,829 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local213756489_0004_m_000000_0' done.
2014-08-22 17:55:43,830 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local213756489_0004_m_000000_0
2014-08-22 17:55:43,830 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2014-08-22 17:55:43,835 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@4ecd51ad
2014-08-22 17:55:43,835 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:43,836 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2014-08-22 17:55:43,837 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2014-08-22 17:55:43,837 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:43,838 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 17:55:43,838 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 17:55:43,849 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:43,849 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/NONE/VALID"]
2014-08-22 17:55:43,857 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local213756489_0004_r_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:43,859 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:43,860 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local213756489_0004_r_000000_0 is allowed to commit now
2014-08-22 17:55:43,864 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local213756489_0004_r_000000_0' to file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/NONE/VALID
2014-08-22 17:55:43,865 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2014-08-22 17:55:43,865 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local213756489_0004_r_000000_0' done.
2014-08-22 17:55:43,877 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/NONE/VALID/_temporary
2014-08-22 17:55:43,891 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:43,905 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 17:55:43,906 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 17:55:43,937 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 17:55:43,937 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:43,938 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/VALID/VALID"]
2014-08-22 17:55:43,938 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 17:55:43,938 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 17:55:43,938 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 17:55:43,939 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...latform/value/VALID/VALID
2014-08-22 17:55:43,954 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:43,992 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local44724969_0005
2014-08-22 17:55:43,993 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 17:55:43,996 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2014-08-22 17:55:43,998 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local44724969_0005_m_000000_0
2014-08-22 17:55:44,000 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@6e9b86ea
2014-08-22 17:55:44,002 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt
2014-08-22 17:55:44,002 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@34189cab
2014-08-22 17:55:44,003 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2014-08-22 17:55:44,004 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2014-08-22 17:55:44,131 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2014-08-22 17:55:44,132 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2014-08-22 17:55:44,133 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 17:55:44,133 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 17:55:44,147 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:44,147 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:44,153 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2014-08-22 17:55:44,156 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2014-08-22 17:55:44,159 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local44724969_0005_m_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:44,161 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2014-08-22 17:55:44,162 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local44724969_0005_m_000000_0' done.
2014-08-22 17:55:44,162 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local44724969_0005_m_000000_0
2014-08-22 17:55:44,162 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2014-08-22 17:55:44,167 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@62ee558f
2014-08-22 17:55:44,167 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:44,168 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2014-08-22 17:55:44,169 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2014-08-22 17:55:44,169 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:44,170 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 17:55:44,170 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 17:55:44,183 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:44,183 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/VALID/VALID"]
2014-08-22 17:55:44,190 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:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2014-08-22 17:55:44,191 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:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2014-08-22 17:55:44,194 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(435)) - job_local44724969_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:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2014-08-22 17:55:44,195 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local44724969_0005 state at FAILED
2014-08-22 17:55:44,195 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2014-08-22 17:55:44,195 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2014-08-22 17:55:44,195 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2014-08-22 17:55:44,202 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] stopping all jobs
2014-08-22 17:55:44,202 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...latform/value/VALID/VALID
2014-08-22 17:55:44,202 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] stopped all jobs
2014-08-22 17:55:44,203 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/VALID/VALID/_temporary
2014-08-22 17:55:44,203 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/value/STRICT/STRICT
2014-08-22 17:55:44,204 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/value/NONE/STRICT
2014-08-22 17:55:44,204 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/value/VALID/VALID
2014-08-22 17:55:44,204 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/value/VALID/STRICT
2014-08-22 17:55:44,205 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/value/NONE/VALID
2014-08-22 17:55:44,222 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 17:55:44,223 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 17:55:44,251 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 17:55:44,251 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:44,252 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/NONE/STRICT"]
2014-08-22 17:55:44,252 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 17:55:44,252 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 17:55:44,252 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 17:55:44,253 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...latform/group/NONE/STRICT
2014-08-22 17:55:44,268 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:44,328 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local161082832_0006
2014-08-22 17:55:44,328 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 17:55:44,332 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2014-08-22 17:55:44,333 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local161082832_0006_m_000000_0
2014-08-22 17:55:44,335 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@55104da7
2014-08-22 17:55:44,338 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt
2014-08-22 17:55:44,338 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@4ad38c3d
2014-08-22 17:55:44,340 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2014-08-22 17:55:44,341 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2014-08-22 17:55:44,707 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2014-08-22 17:55:44,708 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2014-08-22 17:55:44,710 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 17:55:44,710 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 17:55:44,722 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:44,722 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:44,728 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2014-08-22 17:55:44,732 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2014-08-22 17:55:44,734 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local161082832_0006_m_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:44,737 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2014-08-22 17:55:44,738 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local161082832_0006_m_000000_0' done.
2014-08-22 17:55:44,738 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local161082832_0006_m_000000_0
2014-08-22 17:55:44,738 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2014-08-22 17:55:44,742 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@64d1afd3
2014-08-22 17:55:44,743 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:44,744 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2014-08-22 17:55:44,745 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2014-08-22 17:55:44,745 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:44,746 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 17:55:44,746 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 17:55:44,755 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:44,756 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/NONE/STRICT"]
2014-08-22 17:55:44,763 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local161082832_0006_r_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:44,765 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:44,765 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local161082832_0006_r_000000_0 is allowed to commit now
2014-08-22 17:55:44,768 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local161082832_0006_r_000000_0' to file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/NONE/STRICT
2014-08-22 17:55:44,770 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2014-08-22 17:55:44,770 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local161082832_0006_r_000000_0' done.
2014-08-22 17:55:44,785 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/NONE/STRICT/_temporary
2014-08-22 17:55:44,797 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:44,810 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 17:55:44,811 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 17:55:44,838 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 17:55:44,839 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:44,839 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/VALID/STRICT"]
2014-08-22 17:55:44,840 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 17:55:44,840 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 17:55:44,840 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 17:55:44,841 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...atform/group/VALID/STRICT
2014-08-22 17:55:44,855 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:44,887 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1771302652_0007
2014-08-22 17:55:44,887 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 17:55:44,890 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2014-08-22 17:55:44,890 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local1771302652_0007_m_000000_0
2014-08-22 17:55:44,893 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@3fe75e89
2014-08-22 17:55:44,895 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt
2014-08-22 17:55:44,895 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@34768dc8
2014-08-22 17:55:44,897 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2014-08-22 17:55:44,898 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2014-08-22 17:55:45,041 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2014-08-22 17:55:45,041 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2014-08-22 17:55:45,043 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 17:55:45,043 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 17:55:45,053 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:45,053 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:45,057 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2014-08-22 17:55:45,060 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2014-08-22 17:55:45,062 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1771302652_0007_m_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:45,065 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2014-08-22 17:55:45,065 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1771302652_0007_m_000000_0' done.
2014-08-22 17:55:45,065 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local1771302652_0007_m_000000_0
2014-08-22 17:55:45,066 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2014-08-22 17:55:45,070 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@3ceb7830
2014-08-22 17:55:45,071 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:45,072 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2014-08-22 17:55:45,072 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2014-08-22 17:55:45,073 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:45,073 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 17:55:45,073 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 17:55:45,082 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:45,082 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/VALID/STRICT"]
2014-08-22 17:55:45,089 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1771302652_0007_r_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:45,091 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:45,091 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local1771302652_0007_r_000000_0 is allowed to commit now
2014-08-22 17:55:45,094 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local1771302652_0007_r_000000_0' to file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/VALID/STRICT
2014-08-22 17:55:45,096 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2014-08-22 17:55:45,096 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1771302652_0007_r_000000_0' done.
2014-08-22 17:55:45,103 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/VALID/STRICT/_temporary
2014-08-22 17:55:45,114 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:45,127 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 17:55:45,128 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 17:55:45,159 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 17:55:45,160 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:45,160 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/STRICT/STRICT"]
2014-08-22 17:55:45,161 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 17:55:45,161 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 17:55:45,161 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 17:55:45,162 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...tform/group/STRICT/STRICT
2014-08-22 17:55:45,176 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:45,209 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local199886657_0008
2014-08-22 17:55:45,209 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 17:55:45,213 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2014-08-22 17:55:45,213 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local199886657_0008_m_000000_0
2014-08-22 17:55:45,215 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@1f4b52aa
2014-08-22 17:55:45,217 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt
2014-08-22 17:55:45,219 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@4a32ef2d
2014-08-22 17:55:45,221 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2014-08-22 17:55:45,221 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2014-08-22 17:55:45,354 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2014-08-22 17:55:45,354 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2014-08-22 17:55:45,356 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 17:55:45,356 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 17:55:45,367 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:45,368 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:45,372 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2014-08-22 17:55:45,375 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2014-08-22 17:55:45,378 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local199886657_0008_m_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:45,380 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2014-08-22 17:55:45,381 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local199886657_0008_m_000000_0' done.
2014-08-22 17:55:45,381 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local199886657_0008_m_000000_0
2014-08-22 17:55:45,382 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2014-08-22 17:55:45,387 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@6f978b94
2014-08-22 17:55:45,387 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:45,389 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2014-08-22 17:55:45,390 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2014-08-22 17:55:45,391 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:45,391 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 17:55:45,392 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 17:55:45,403 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:45,403 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/STRICT/STRICT"]
2014-08-22 17:55:45,411 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:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2014-08-22 17:55:45,418 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:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2014-08-22 17:55:45,424 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(435)) - job_local199886657_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:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2014-08-22 17:55:45,431 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local199886657_0008 state at FAILED
2014-08-22 17:55:45,432 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2014-08-22 17:55:45,432 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2014-08-22 17:55:45,432 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2014-08-22 17:55:45,435 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] stopping all jobs
2014-08-22 17:55:45,435 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...tform/group/STRICT/STRICT
2014-08-22 17:55:45,435 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] stopped all jobs
2014-08-22 17:55:45,436 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/STRICT/STRICT/_temporary
2014-08-22 17:55:45,449 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 17:55:45,450 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 17:55:45,478 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 17:55:45,478 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:45,479 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/NONE/VALID"]
2014-08-22 17:55:45,479 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 17:55:45,479 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 17:55:45,479 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 17:55:45,480 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...platform/group/NONE/VALID
2014-08-22 17:55:45,493 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:45,527 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local157798502_0009
2014-08-22 17:55:45,528 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 17:55:45,531 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2014-08-22 17:55:45,531 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local157798502_0009_m_000000_0
2014-08-22 17:55:45,533 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@5c09036e
2014-08-22 17:55:45,535 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt
2014-08-22 17:55:45,535 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@44b1406b
2014-08-22 17:55:45,537 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2014-08-22 17:55:45,537 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2014-08-22 17:55:45,672 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2014-08-22 17:55:45,673 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2014-08-22 17:55:45,674 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 17:55:45,675 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 17:55:45,686 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:45,686 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:45,690 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2014-08-22 17:55:45,693 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2014-08-22 17:55:45,695 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local157798502_0009_m_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:45,698 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2014-08-22 17:55:45,698 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local157798502_0009_m_000000_0' done.
2014-08-22 17:55:45,699 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local157798502_0009_m_000000_0
2014-08-22 17:55:45,699 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2014-08-22 17:55:45,704 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@381172c5
2014-08-22 17:55:45,704 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:45,705 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2014-08-22 17:55:45,706 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2014-08-22 17:55:45,707 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:45,707 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 17:55:45,707 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 17:55:45,716 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:45,716 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/NONE/VALID"]
2014-08-22 17:55:45,723 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local157798502_0009_r_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:45,725 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:45,725 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local157798502_0009_r_000000_0 is allowed to commit now
2014-08-22 17:55:45,729 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local157798502_0009_r_000000_0' to file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/NONE/VALID
2014-08-22 17:55:45,731 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2014-08-22 17:55:45,731 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local157798502_0009_r_000000_0' done.
2014-08-22 17:55:45,744 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/NONE/VALID/_temporary
2014-08-22 17:55:45,757 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:45,785 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 17:55:45,786 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 17:55:45,811 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 17:55:45,811 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:45,812 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/VALID/VALID"]
2014-08-22 17:55:45,813 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 17:55:45,813 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 17:55:45,813 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 17:55:45,814 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...latform/group/VALID/VALID
2014-08-22 17:55:45,826 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:45,853 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local502274444_0010
2014-08-22 17:55:45,857 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2014-08-22 17:55:45,857 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 17:55:45,857 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local502274444_0010_m_000000_0
2014-08-22 17:55:45,861 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@397af435
2014-08-22 17:55:45,863 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt
2014-08-22 17:55:45,863 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@38f0b51d
2014-08-22 17:55:45,866 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2014-08-22 17:55:45,866 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2014-08-22 17:55:46,297 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2014-08-22 17:55:46,298 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2014-08-22 17:55:46,300 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 17:55:46,300 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 17:55:46,311 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:46,312 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:46,316 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2014-08-22 17:55:46,319 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2014-08-22 17:55:46,321 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local502274444_0010_m_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:46,324 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2014-08-22 17:55:46,324 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local502274444_0010_m_000000_0' done.
2014-08-22 17:55:46,324 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local502274444_0010_m_000000_0
2014-08-22 17:55:46,324 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2014-08-22 17:55:46,328 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@4daa34dc
2014-08-22 17:55:46,329 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:46,330 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2014-08-22 17:55:46,330 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2014-08-22 17:55:46,331 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:46,331 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 17:55:46,331 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 17:55:46,341 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:46,341 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/VALID/VALID"]
2014-08-22 17:55:46,347 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:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2014-08-22 17:55:46,348 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:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2014-08-22 17:55:46,350 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(435)) - job_local502274444_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:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2014-08-22 17:55:46,357 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local502274444_0010 state at FAILED
2014-08-22 17:55:46,357 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2014-08-22 17:55:46,357 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2014-08-22 17:55:46,357 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2014-08-22 17:55:46,361 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] stopping all jobs
2014-08-22 17:55:46,362 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...latform/group/VALID/VALID
2014-08-22 17:55:46,362 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] stopped all jobs
2014-08-22 17:55:46,363 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/group/VALID/VALID/_temporary
2014-08-22 17:55:46,363 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/group/STRICT/STRICT
2014-08-22 17:55:46,363 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/group/VALID/STRICT
2014-08-22 17:55:46,364 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/group/VALID/VALID
2014-08-22 17:55:46,364 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/group/NONE/STRICT
2014-08-22 17:55:46,364 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/group/NONE/VALID
2014-08-22 17:55:46,377 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 17:55:46,377 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 17:55:46,400 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 17:55:46,401 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:46,402 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/fail"]
2014-08-22 17:55:46,402 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 17:55:46,402 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 17:55:46,403 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 17:55:46,404 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...edassertionsplatform/fail
2014-08-22 17:55:46,416 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:46,443 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1602508236_0011
2014-08-22 17:55:46,443 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 17:55:46,446 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2014-08-22 17:55:46,446 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local1602508236_0011_m_000000_0
2014-08-22 17:55:46,448 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@55a6c368
2014-08-22 17:55:46,450 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt
2014-08-22 17:55:46,451 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@73e04a35
2014-08-22 17:55:46,452 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2014-08-22 17:55:46,453 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2014-08-22 17:55:46,478 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2014-08-22 17:55:46,478 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2014-08-22 17:55:46,481 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 17:55:46,481 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 17:55:46,492 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:46,492 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:46,497 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2014-08-22 17:55:46,499 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2014-08-22 17:55:46,501 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1602508236_0011_m_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:46,504 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2014-08-22 17:55:46,505 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1602508236_0011_m_000000_0' done.
2014-08-22 17:55:46,505 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local1602508236_0011_m_000000_0
2014-08-22 17:55:46,505 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2014-08-22 17:55:46,510 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@27573872
2014-08-22 17:55:46,510 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:46,511 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2014-08-22 17:55:46,512 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2014-08-22 17:55:46,512 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:46,513 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 17:55:46,513 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 17:55:46,523 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:46,523 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/fail"]
2014-08-22 17:55:46,529 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:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2014-08-22 17:55:46,530 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:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2014-08-22 17:55:46,532 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(435)) - job_local1602508236_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:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2014-08-22 17:55:46,535 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local1602508236_0011 state at FAILED
2014-08-22 17:55:46,535 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2014-08-22 17:55:46,535 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2014-08-22 17:55:46,535 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2014-08-22 17:55:46,537 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] stopping all jobs
2014-08-22 17:55:46,538 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...edassertionsplatform/fail
2014-08-22 17:55:46,538 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] stopped all jobs
2014-08-22 17:55:46,538 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] shutting down job executor
2014-08-22 17:55:46,539 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] shutdown complete
2014-08-22 17:55:46,539 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/fail/_temporary
2014-08-22 17:55:46,539 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/fail
2014-08-22 17:55:46,552 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 17:55:46,552 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 17:55:46,574 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 17:55:46,574 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:46,575 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/pass"]
2014-08-22 17:55:46,575 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 17:55:46,576 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 17:55:46,576 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 17:55:46,578 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...edassertionsplatform/pass
2014-08-22 17:55:46,590 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:46,616 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local798739876_0012
2014-08-22 17:55:46,616 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 17:55:46,619 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2014-08-22 17:55:46,619 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local798739876_0012_m_000000_0
2014-08-22 17:55:46,621 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@6483dae1
2014-08-22 17:55:46,623 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt
2014-08-22 17:55:46,623 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@22aed3a5
2014-08-22 17:55:46,625 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2014-08-22 17:55:46,626 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2014-08-22 17:55:46,760 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2014-08-22 17:55:46,760 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2014-08-22 17:55:46,762 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 17:55:46,762 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 17:55:46,772 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:46,772 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:46,776 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2014-08-22 17:55:46,778 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2014-08-22 17:55:46,780 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local798739876_0012_m_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:46,783 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2014-08-22 17:55:46,783 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local798739876_0012_m_000000_0' done.
2014-08-22 17:55:46,783 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local798739876_0012_m_000000_0
2014-08-22 17:55:46,783 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2014-08-22 17:55:46,788 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@1f26ecd2
2014-08-22 17:55:46,789 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:46,790 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2014-08-22 17:55:46,790 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2014-08-22 17:55:46,791 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:46,791 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 17:55:46,791 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 17:55:46,800 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:46,801 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/pass"]
2014-08-22 17:55:46,809 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local798739876_0012_r_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:46,810 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:46,811 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local798739876_0012_r_000000_0 is allowed to commit now
2014-08-22 17:55:46,813 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local798739876_0012_r_000000_0' to file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/pass
2014-08-22 17:55:46,815 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2014-08-22 17:55:46,815 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local798739876_0012_r_000000_0' done.
2014-08-22 17:55:46,821 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/pass/_temporary
2014-08-22 17:55:46,831 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:46,833 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/pass
2014-08-22 17:55:46,845 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 17:55:46,845 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 17:55:46,865 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 17:55:46,866 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:46,867 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/fail"]
2014-08-22 17:55:46,868 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 17:55:46,868 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 17:55:46,869 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 17:55:46,870 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...rtionsplatform/value/fail
2014-08-22 17:55:46,881 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:46,906 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local1470184399_0013
2014-08-22 17:55:46,907 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 17:55:46,910 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2014-08-22 17:55:46,911 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local1470184399_0013_m_000000_0
2014-08-22 17:55:46,912 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@79fc7299
2014-08-22 17:55:46,913 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt
2014-08-22 17:55:46,914 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@4d1b92ef
2014-08-22 17:55:46,915 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2014-08-22 17:55:46,915 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2014-08-22 17:55:47,045 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2014-08-22 17:55:47,045 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2014-08-22 17:55:47,046 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 17:55:47,046 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 17:55:47,055 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:47,055 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:47,059 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2014-08-22 17:55:47,061 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2014-08-22 17:55:47,063 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local1470184399_0013_m_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:47,066 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2014-08-22 17:55:47,066 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local1470184399_0013_m_000000_0' done.
2014-08-22 17:55:47,066 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local1470184399_0013_m_000000_0
2014-08-22 17:55:47,067 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2014-08-22 17:55:47,115 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@c265121
2014-08-22 17:55:47,116 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:47,117 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2014-08-22 17:55:47,117 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2014-08-22 17:55:47,118 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:47,118 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 17:55:47,118 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 17:55:47,126 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:47,126 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/fail"]
2014-08-22 17:55:47,132 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:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2014-08-22 17:55:47,132 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:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2014-08-22 17:55:47,135 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(435)) - job_local1470184399_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:145)
at cascading.tuple.TupleEntryCollector.add(TupleEntryCollector.java:133)
at cascading.operation.aggregator.Count.complete(Count.java:82)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:151)
at cascading.flow.stream.AggregatorEveryStage.completeGroup(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:51)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:522)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:421)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:398)
2014-08-22 17:55:47,140 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] hadoop job job_local1470184399_0013 state at FAILED
2014-08-22 17:55:47,140 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] failure info: NA
2014-08-22 17:55:47,140 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events identify failed tasks
2014-08-22 17:55:47,140 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [test] task completion events count: 0
2014-08-22 17:55:47,142 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] stopping all jobs
2014-08-22 17:55:47,142 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] stopping: (1/1) ...rtionsplatform/value/fail
2014-08-22 17:55:47,143 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] stopped all jobs
2014-08-22 17:55:47,143 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] shutting down job executor
2014-08-22 17:55:47,143 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] shutdown complete
2014-08-22 17:55:47,143 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/fail/_temporary
2014-08-22 17:55:47,144 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/value/fail
2014-08-22 17:55:47,157 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 17:55:47,158 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop/2.5.6/a36851b185807587c9a4b9e914f06c5ea27801c9/cascading-hadoop-2.5.6.jar
2014-08-22 17:55:47,177 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting
2014-08-22 17:55:47,178 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:47,178 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/pass"]
2014-08-22 17:55:47,179 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] parallel execution is enabled: false
2014-08-22 17:55:47,179 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] starting jobs: 1
2014-08-22 17:55:47,179 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [test] allocating threads: 1
2014-08-22 17:55:47,180 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] starting step: (1/1) ...rtionsplatform/value/pass
2014-08-22 17:55:47,192 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:47,217 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] submitted hadoop job: job_local479509411_0014
2014-08-22 17:55:47,217 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [test] tracking url: http://localhost:8080/
2014-08-22 17:55:47,219 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(340)) - Waiting for map tasks
2014-08-22 17:55:47,220 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(204)) - Starting task: attempt_local479509411_0014_m_000000_0
2014-08-22 17:55:47,221 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@6750cf54
2014-08-22 17:55:47,223 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt
2014-08-22 17:55:47,223 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(455)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@2b2143d8
2014-08-22 17:55:47,225 INFO mapred.MapTask (MapTask.java:runOldMapper(419)) - numReduceTasks: 1
2014-08-22 17:55:47,226 INFO mapred.MapTask (MapTask.java:<init>(949)) - io.sort.mb = 100
2014-08-22 17:55:47,353 INFO mapred.MapTask (MapTask.java:<init>(961)) - data buffer = 79691776/99614720
2014-08-22 17:55:47,354 INFO mapred.MapTask (MapTask.java:<init>(962)) - record buffer = 262144/327680
2014-08-22 17:55:47,355 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 17:55:47,356 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 17:55:47,364 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt"]
2014-08-22 17:55:47,364 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:47,369 INFO mapred.MapTask (MapTask.java:flush(1289)) - Starting flush of map output
2014-08-22 17:55:47,371 INFO mapred.MapTask (MapTask.java:sortAndSpill(1471)) - Finished spill 0
2014-08-22 17:55:47,373 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local479509411_0014_m_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:47,375 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/classes/test/data/apache.10.txt:0+1449
2014-08-22 17:55:47,376 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local479509411_0014_m_000000_0' done.
2014-08-22 17:55:47,376 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(229)) - Finishing task: attempt_local479509411_0014_m_000000_0
2014-08-22 17:55:47,377 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(348)) - Map task executor complete.
2014-08-22 17:55:47,380 INFO mapred.Task (Task.java:initialize(534)) - Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@27beb7ec
2014-08-22 17:55:47,381 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:47,382 INFO mapred.Merger (Merger.java:merge(408)) - Merging 1 sorted segments
2014-08-22 17:55:47,382 INFO mapred.Merger (Merger.java:merge(491)) - Down to the last merge-pass, with 1 segments left of total size: 709 bytes
2014-08-22 17:55:47,383 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:47,383 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 17:55:47,383 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 17:55:47,390 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(test)[by:[{1}:'method']]
2014-08-22 17:55:47,390 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/pass"]
2014-08-22 17:55:47,395 INFO mapred.Task (Task.java:done(858)) - Task:attempt_local479509411_0014_r_000000_0 is done. And is in the process of commiting
2014-08-22 17:55:47,398 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) -
2014-08-22 17:55:47,399 INFO mapred.Task (Task.java:commit(1011)) - Task attempt_local479509411_0014_r_000000_0 is allowed to commit now
2014-08-22 17:55:47,402 INFO mapred.FileOutputCommitter (FileOutputCommitter.java:commitTask(138)) - Saved output of task 'attempt_local479509411_0014_r_000000_0' to file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/pass
2014-08-22 17:55:47,403 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(466)) - reduce > reduce
2014-08-22 17:55:47,403 INFO mapred.Task (Task.java:sendDone(970)) - Task 'attempt_local479509411_0014_r_000000_0' done.
2014-08-22 17:55:47,411 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output/hadoop/appliedassertionsplatform/value/pass/_temporary
2014-08-22 17:55:47,422 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(199)) - Total input paths to process : 1
2014-08-22 17:55:47,423 INFO cascading.PlatformTestCase (PlatformTestCase.java:tearDown(209)) - copying to local /opt/buildAgent-8.0.3/work/3945655b04626318/apache-1.2.x/build/test/output//hadoop/appliedassertionsplatform/value/pass