2014-08-22 21:25:54,444 INFO platform.PlatformRunner (PlatformRunner.java:getPlatformClassesFromClasspath(187)) - found 1 test platforms from classpath
2014-08-22 21:25:54,508 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(237)) - installing platform: hadoop2-mr1
2014-08-22 21:25:54,509 INFO platform.PlatformRunner (PlatformRunner.java:addPlatform(238)) - running test: cascading.stats.hadoop.CascadingStatsLocalHadoopErrorPlatformTest
2014-08-22 21:25:54,922 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 21:25:54,925 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.5.6/31997f144a2e73eebf04d45ed31402ee30118b2/cascading-hadoop2-mr1-2.5.6.jar
2014-08-22 21:25:54,953 INFO property.AppProps (AppProps.java:getAppID(162)) - using app.id: 22883E1D56A94F0E84B073E1550690FA
2014-08-22 21:25:55,253 WARN util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2014-08-22 21:25:55,477 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2014-08-22 21:25:55,512 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2014-08-22 21:25:55,516 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2014-08-22 21:25:55,597 INFO util.Version (Version.java:printBanner(78)) - Concurrent, Inc - Cascading 2.5.6
2014-08-22 21:25:55,597 INFO cascade.Cascade (Cascade.java:logInfo(991)) - [reducer fail test] starting
2014-08-22 21:25:55,601 INFO cascade.Cascade (Cascade.java:logInfo(991)) - [reducer fail test] parallel execution is enabled: true
2014-08-22 21:25:55,601 INFO cascade.Cascade (Cascade.java:logInfo(991)) - [reducer fail test] starting flows: 1
2014-08-22 21:25:55,601 INFO cascade.Cascade (Cascade.java:logInfo(991)) - [reducer fail test] allocating threads: 1
2014-08-22 21:25:55,602 INFO cascade.Cascade (Cascade.java:logInfo(991)) - [reducer fail test] starting flow: reducer fail test
2014-08-22 21:25:55,606 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [reducer fail test] at least one sink is marked for delete
2014-08-22 21:25:55,611 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [reducer fail test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2014-08-22 21:25:55,697 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [reducer fail test] starting
2014-08-22 21:25:55,698 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [reducer fail test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2014-08-22 21:25:55,698 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [reducer fail test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/test/output/hadoop2-mr1/cascadingstatslocalhadooperrorplatform/reducerfail"]
2014-08-22 21:25:55,699 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [reducer fail test] parallel execution is enabled: false
2014-08-22 21:25:55,699 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [reducer fail test] starting jobs: 1
2014-08-22 21:25:55,700 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [reducer fail test] allocating threads: 1
2014-08-22 21:25:55,701 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [reducer fail test] starting step: (1/1) ...errorplatform/reducerfail
2014-08-22 21:25:55,729 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - session.id is deprecated. Instead, use dfs.metrics.session-id
2014-08-22 21:25:55,731 INFO jvm.JvmMetrics (JvmMetrics.java:init(76)) - Initializing JVM Metrics with processName=JobTracker, sessionId=
2014-08-22 21:25:55,759 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-08-22 21:25:56,176 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-08-22 21:25:56,220 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2014-08-22 21:25:56,399 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local838928212_0001
2014-08-22 21:25:56,449 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/test/tmp/mapred/staging/teamcity838928212/.staging/job_local838928212_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-08-22 21:25:56,450 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/test/tmp/mapred/staging/teamcity838928212/.staging/job_local838928212_0001/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-08-22 21:25:56,666 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local838928212_0001/job_local838928212_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-08-22 21:25:56,667 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local838928212_0001/job_local838928212_0001.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-08-22 21:25:56,681 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2014-08-22 21:25:56,683 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2014-08-22 21:25:56,686 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [reducer fail test] submitted hadoop job: job_local838928212_0001
2014-08-22 21:25:56,686 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [reducer fail test] tracking url: http://localhost:8080/
2014-08-22 21:25:56,686 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2014-08-22 21:25:56,751 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2014-08-22 21:25:56,756 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local838928212_0001_m_000000_0
2014-08-22 21:25:56,800 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-08-22 21:25:56,811 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/classes/test/data/apache.10.txt
2014-08-22 21:25:56,812 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@6070c38c
2014-08-22 21:25:56,823 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 1
2014-08-22 21:25:56,831 INFO mapred.MapTask (MapTask.java:createSortingCollector(388)) - Map output collector class = org.apache.hadoop.mapred.MapTask$MapOutputBuffer
2014-08-22 21:25:56,984 INFO mapred.MapTask (MapTask.java:setEquator(1181)) - (EQUATOR) 0 kvi 26214396(104857584)
2014-08-22 21:25:56,984 INFO mapred.MapTask (MapTask.java:init(975)) - mapreduce.task.io.sort.mb: 100
2014-08-22 21:25:56,985 INFO mapred.MapTask (MapTask.java:init(976)) - soft limit at 83886080
2014-08-22 21:25:56,985 INFO mapred.MapTask (MapTask.java:init(977)) - bufstart = 0; bufvoid = 104857600
2014-08-22 21:25:56,985 INFO mapred.MapTask (MapTask.java:init(978)) - kvstart = 26214396; length = 6553600
2014-08-22 21:25:57,009 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 21:25:57,009 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 21:25:57,059 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.task.partition is deprecated. Instead, use mapreduce.task.partition
2014-08-22 21:25:57,079 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2014-08-22 21:25:57,079 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: GroupBy(failing reducer)[by:[{1}:'ip']]
2014-08-22 21:25:57,095 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) -
2014-08-22 21:25:57,095 INFO mapred.MapTask (MapTask.java:flush(1435)) - Starting flush of map output
2014-08-22 21:25:57,096 INFO mapred.MapTask (MapTask.java:flush(1453)) - Spilling map output
2014-08-22 21:25:57,096 INFO mapred.MapTask (MapTask.java:flush(1454)) - bufstart = 0; bufend = 210; bufvoid = 104857600
2014-08-22 21:25:57,096 INFO mapred.MapTask (MapTask.java:flush(1456)) - kvstart = 26214396(104857584); kvend = 26214360(104857440); length = 37/6553600
2014-08-22 21:25:57,110 INFO mapred.MapTask (MapTask.java:sortAndSpill(1639)) - Finished spill 0
2014-08-22 21:25:57,115 INFO mapred.Task (Task.java:done(995)) - Task:attempt_local838928212_0001_m_000000_0 is done. And is in the process of committing
2014-08-22 21:25:57,126 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/classes/test/data/apache.10.txt:0+1449
2014-08-22 21:25:57,126 INFO mapred.Task (Task.java:sendDone(1115)) - Task 'attempt_local838928212_0001_m_000000_0' done.
2014-08-22 21:25:57,126 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(249)) - Finishing task: attempt_local838928212_0001_m_000000_0
2014-08-22 21:25:57,127 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2014-08-22 21:25:57,130 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for reduce tasks
2014-08-22 21:25:57,130 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(302)) - Starting task: attempt_local838928212_0001_r_000000_0
2014-08-22 21:25:57,139 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-08-22 21:25:57,142 INFO mapred.ReduceTask (ReduceTask.java:run(362)) - Using ShuffleConsumerPlugin: org.apache.hadoop.mapreduce.task.reduce.Shuffle@30cafa1
2014-08-22 21:25:57,157 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:<init>(193)) - MergerManager: memoryLimit=493250144, maxSingleShuffleLimit=123312536, mergeThreshold=325545120, ioSortFactor=10, memToMemMergeOutputsThreshold=10
2014-08-22 21:25:57,160 INFO reduce.EventFetcher (EventFetcher.java:run(61)) - attempt_local838928212_0001_r_000000_0 Thread started: EventFetcher for fetching Map Completion Events
2014-08-22 21:25:57,195 INFO reduce.LocalFetcher (LocalFetcher.java:copyMapOutput(140)) - localfetcher#1 about to shuffle output of map attempt_local838928212_0001_m_000000_0 decomp: 232 len: 236 to MEMORY
2014-08-22 21:25:57,201 INFO reduce.InMemoryMapOutput (InMemoryMapOutput.java:shuffle(100)) - Read 232 bytes from map-output for attempt_local838928212_0001_m_000000_0
2014-08-22 21:25:57,248 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:closeInMemoryFile(307)) - closeInMemoryFile -> map-output of size: 232, inMemoryMapOutputs.size() -> 1, commitMemory -> 0, usedMemory ->232
2014-08-22 21:25:57,249 INFO reduce.EventFetcher (EventFetcher.java:run(76)) - EventFetcher is interrupted.. Returning
2014-08-22 21:25:57,251 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-08-22 21:25:57,252 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(667)) - finalMerge called with 1 in-memory map-outputs and 0 on-disk map-outputs
2014-08-22 21:25:57,261 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-08-22 21:25:57,261 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 211 bytes
2014-08-22 21:25:57,264 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(742)) - Merged 1 segments, 232 bytes to disk to satisfy reduce memory limit
2014-08-22 21:25:57,265 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(772)) - Merging 1 files, 236 bytes from disk
2014-08-22 21:25:57,265 INFO reduce.MergeManagerImpl (MergeManagerImpl.java:finalMerge(787)) - Merging 0 segments, 0 bytes from memory into reduce
2014-08-22 21:25:57,266 INFO mapred.Merger (Merger.java:merge(589)) - Merging 1 sorted segments
2014-08-22 21:25:57,266 INFO mapred.Merger (Merger.java:merge(688)) - Down to the last merge-pass, with 1 segments left of total size: 211 bytes
2014-08-22 21:25:57,267 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - 1 / 1 copied.
2014-08-22 21:25:57,269 INFO hadoop.FlowReducer (FlowReducer.java:configure(78)) - cascading version: 2.5.6
2014-08-22 21:25:57,269 INFO hadoop.FlowReducer (FlowReducer.java:configure(79)) - child jvm opts: -Xmx200m
2014-08-22 21:25:57,286 INFO hadoop.FlowReducer (FlowReducer.java:configure(97)) - sourcing from: GroupBy(failing reducer)[by:[{1}:'ip']]
2014-08-22 21:25:57,286 INFO hadoop.FlowReducer (FlowReducer.java:configure(100)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/test/output/hadoop2-mr1/cascadingstatslocalhadooperrorplatform/reducerfail"]
2014-08-22 21:25:57,315 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.pipe.OperatorException: [failing reducer][cascading.stats.hadoop.CascadingStatsLocalHadoopErrorPlatformTest.testLocalErrorReportingInReducer(CascadingStatsLocalHadoopErrorPlatformTest.java:124)] operator Every failed executing operation: TestFailAggregator[decl:'count']
at cascading.flow.stream.AggregatorEveryStage.receive(AggregatorEveryStage.java:136)
at cascading.flow.stream.AggregatorEveryStage.receive(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:49)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.RuntimeException: failed
at cascading.TestFailAggregator.aggregate(TestFailAggregator.java:54)
at cascading.flow.stream.AggregatorEveryStage.receive(AggregatorEveryStage.java:128)
... 14 more
2014-08-22 21:25:57,319 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - reduce task executor complete.
2014-08-22 21:25:57,322 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local838928212_0001
java.lang.Exception: cascading.pipe.OperatorException: [failing reducer][cascading.stats.hadoop.CascadingStatsLocalHadoopErrorPlatformTest.testLocalErrorReportingInReducer(CascadingStatsLocalHadoopErrorPlatformTest.java:124)] operator Every failed executing operation: TestFailAggregator[decl:'count']
at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:529)
Caused by: cascading.pipe.OperatorException: [failing reducer][cascading.stats.hadoop.CascadingStatsLocalHadoopErrorPlatformTest.testLocalErrorReportingInReducer(CascadingStatsLocalHadoopErrorPlatformTest.java:124)] operator Every failed executing operation: TestFailAggregator[decl:'count']
at cascading.flow.stream.AggregatorEveryStage.receive(AggregatorEveryStage.java:136)
at cascading.flow.stream.AggregatorEveryStage.receive(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:49)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.RuntimeException: failed
at cascading.TestFailAggregator.aggregate(TestFailAggregator.java:54)
at cascading.flow.stream.AggregatorEveryStage.receive(AggregatorEveryStage.java:128)
... 14 more
2014-08-22 21:26:01,688 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [reducer fail test] hadoop job job_local838928212_0001 state at FAILED
2014-08-22 21:26:01,689 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [reducer fail test] failure info: NA
2014-08-22 21:26:01,690 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [reducer fail test] task completion events identify failed tasks
2014-08-22 21:26:01,690 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [reducer fail test] task completion events count: 0
2014-08-22 21:26:01,712 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [reducer fail test] stopping all jobs
2014-08-22 21:26:01,712 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [reducer fail test] stopping: (1/1) ...errorplatform/reducerfail
2014-08-22 21:26:01,712 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [reducer fail test] stopped all jobs
2014-08-22 21:26:01,712 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [reducer fail test] shutting down job executor
2014-08-22 21:26:01,713 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [reducer fail test] shutdown complete
2014-08-22 21:26:01,715 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/test/output/hadoop2-mr1/cascadingstatslocalhadooperrorplatform/reducerfail/_temporary
2014-08-22 21:26:01,716 WARN cascade.Cascade (Cascade.java:logWarn(1001)) - [reducer fail test] flow failed: reducer fail test
cascading.flow.FlowException: local step failed
at cascading.flow.planner.FlowStepJob.blockOnJob(FlowStepJob.java:219)
at cascading.flow.planner.FlowStepJob.start(FlowStepJob.java:149)
at cascading.flow.planner.FlowStepJob.call(FlowStepJob.java:124)
at cascading.flow.planner.FlowStepJob.call(FlowStepJob.java:43)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
at java.lang.Thread.run(Thread.java:662)
Caused by: cascading.pipe.OperatorException: [failing reducer][cascading.stats.hadoop.CascadingStatsLocalHadoopErrorPlatformTest.testLocalErrorReportingInReducer(CascadingStatsLocalHadoopErrorPlatformTest.java:124)] operator Every failed executing operation: TestFailAggregator[decl:'count']
at cascading.flow.stream.AggregatorEveryStage.receive(AggregatorEveryStage.java:136)
at cascading.flow.stream.AggregatorEveryStage.receive(AggregatorEveryStage.java:39)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:49)
at cascading.flow.stream.OpenReducingDuct.receive(OpenReducingDuct.java:28)
at cascading.flow.hadoop.stream.HadoopGroupGate.run(HadoopGroupGate.java:93)
at cascading.flow.hadoop.FlowReducer.reduce(FlowReducer.java:136)
at org.apache.hadoop.mapred.ReduceTask.runOldReducer(ReduceTask.java:444)
at org.apache.hadoop.mapred.ReduceTask.run(ReduceTask.java:392)
at org.apache.hadoop.mapred.LocalJobRunner$Job$ReduceTaskRunnable.run(LocalJobRunner.java:319)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439)
... 5 more
Caused by: java.lang.RuntimeException: failed
at cascading.TestFailAggregator.aggregate(TestFailAggregator.java:54)
at cascading.flow.stream.AggregatorEveryStage.receive(AggregatorEveryStage.java:128)
... 14 more
2014-08-22 21:26:01,717 INFO cascade.Cascade (Cascade.java:logInfo(991)) - [reducer fail test] stopping all flows
2014-08-22 21:26:01,717 INFO cascade.Cascade (Cascade.java:logInfo(991)) - [reducer fail test] stopping flow: reducer fail test
2014-08-22 21:26:01,718 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [reducer fail test] stopping all jobs
2014-08-22 21:26:01,718 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [reducer fail test] stopping: (1/1) ...errorplatform/reducerfail
2014-08-22 21:26:01,718 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [reducer fail test] stopped all jobs
2014-08-22 21:26:01,718 INFO cascade.Cascade (Cascade.java:logInfo(991)) - [reducer fail test] stopped all flows
2014-08-22 21:26:01,750 INFO util.HadoopUtil (HadoopUtil.java:findMainClass(336)) - using default application jar, may cause class not found exceptions on the cluster
2014-08-22 21:26:01,751 INFO planner.HadoopPlanner (HadoopPlanner.java:initialize(225)) - using application jar: /opt/concurrent/home/teamcity/.gradle/caches/modules-2/files-2.1/cascading/cascading-hadoop2-mr1/2.5.6/31997f144a2e73eebf04d45ed31402ee30118b2/cascading-hadoop2-mr1-2.5.6.jar
2014-08-22 21:26:01,763 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.used.genericoptionsparser is deprecated. Instead, use mapreduce.client.genericoptionsparser.used
2014-08-22 21:26:01,769 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address
2014-08-22 21:26:01,770 INFO Configuration.deprecation (Configuration.java:warnOnceIfDeprecated(996)) - mapred.output.compress is deprecated. Instead, use mapreduce.output.fileoutputformat.compress
2014-08-22 21:26:01,785 INFO cascade.Cascade (Cascade.java:logInfo(991)) - [mapper fail test] starting
2014-08-22 21:26:01,787 INFO cascade.Cascade (Cascade.java:logInfo(991)) - [mapper fail test] parallel execution is enabled: true
2014-08-22 21:26:01,787 INFO cascade.Cascade (Cascade.java:logInfo(991)) - [mapper fail test] starting flows: 1
2014-08-22 21:26:01,787 INFO cascade.Cascade (Cascade.java:logInfo(991)) - [mapper fail test] allocating threads: 1
2014-08-22 21:26:01,789 INFO cascade.Cascade (Cascade.java:logInfo(991)) - [mapper fail test] starting flow: mapper fail test
2014-08-22 21:26:01,792 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [mapper fail test] at least one sink is marked for delete
2014-08-22 21:26:01,792 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [mapper fail test] sink oldest modified date: Wed Dec 31 23:59:59 UTC 1969
2014-08-22 21:26:01,798 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [mapper fail test] starting
2014-08-22 21:26:01,798 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [mapper fail test] source: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2014-08-22 21:26:01,799 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [mapper fail test] sink: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/test/output/hadoop2-mr1/cascadingstatslocalhadooperrorplatform/mapperfail"]
2014-08-22 21:26:01,799 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [mapper fail test] parallel execution is enabled: false
2014-08-22 21:26:01,799 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [mapper fail test] starting jobs: 1
2014-08-22 21:26:01,799 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [mapper fail test] allocating threads: 1
2014-08-22 21:26:01,800 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [mapper fail test] starting step: (1/1) ...perrorplatform/mapperfail
2014-08-22 21:26:01,802 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-08-22 21:26:01,805 INFO jvm.JvmMetrics (JvmMetrics.java:init(71)) - Cannot initialize JVM Metrics with processName=JobTracker, sessionId= - already initialized
2014-08-22 21:26:01,841 INFO mapred.FileInputFormat (FileInputFormat.java:listStatus(253)) - Total input paths to process : 1
2014-08-22 21:26:01,868 INFO mapreduce.JobSubmitter (JobSubmitter.java:submitJobInternal(396)) - number of splits:1
2014-08-22 21:26:01,908 INFO mapreduce.JobSubmitter (JobSubmitter.java:printTokens(479)) - Submitting tokens for job: job_local65890607_0002
2014-08-22 21:26:01,932 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/test/tmp/mapred/staging/teamcity65890607/.staging/job_local65890607_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-08-22 21:26:01,932 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/test/tmp/mapred/staging/teamcity65890607/.staging/job_local65890607_0002/job.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-08-22 21:26:02,027 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local65890607_0002/job_local65890607_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.retry.interval; Ignoring.
2014-08-22 21:26:02,028 WARN conf.Configuration (Configuration.java:loadProperty(2345)) - file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/test/tmp/mapred/local/localRunner/teamcity/job_local65890607_0002/job_local65890607_0002.xml:an attempt to override final parameter: mapreduce.job.end-notification.max.attempts; Ignoring.
2014-08-22 21:26:02,030 INFO mapreduce.Job (Job.java:submit(1289)) - The url to track the job: http://localhost:8080/
2014-08-22 21:26:02,030 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [mapper fail test] submitted hadoop job: job_local65890607_0002
2014-08-22 21:26:02,030 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [mapper fail test] tracking url: http://localhost:8080/
2014-08-22 21:26:02,030 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(471)) - OutputCommitter set in config null
2014-08-22 21:26:02,031 INFO mapred.LocalJobRunner (LocalJobRunner.java:createOutputCommitter(489)) - OutputCommitter is org.apache.hadoop.mapred.FileOutputCommitter
2014-08-22 21:26:02,035 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(448)) - Waiting for map tasks
2014-08-22 21:26:02,035 INFO mapred.LocalJobRunner (LocalJobRunner.java:run(224)) - Starting task: attempt_local65890607_0002_m_000000_0
2014-08-22 21:26:02,038 INFO mapred.Task (Task.java:initialize(581)) - Using ResourceCalculatorProcessTree : [ ]
2014-08-22 21:26:02,040 INFO io.MultiInputSplit (MultiInputSplit.java:readFields(161)) - current split input path: file:/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/classes/test/data/apache.10.txt
2014-08-22 21:26:02,040 INFO mapred.MapTask (MapTask.java:updateJobWithSplit(462)) - Processing split: cascading.tap.hadoop.io.MultiInputSplit@697a906e
2014-08-22 21:26:02,042 INFO mapred.MapTask (MapTask.java:runOldMapper(416)) - numReduceTasks: 0
2014-08-22 21:26:02,054 INFO hadoop.FlowMapper (FlowMapper.java:configure(71)) - cascading version: 2.5.6
2014-08-22 21:26:02,054 INFO hadoop.FlowMapper (FlowMapper.java:configure(72)) - child jvm opts: -Xmx200m
2014-08-22 21:26:02,064 INFO hadoop.FlowMapper (FlowMapper.java:configure(87)) - sourcing from: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/classes/test/data/apache.10.txt"]
2014-08-22 21:26:02,064 INFO hadoop.FlowMapper (FlowMapper.java:configure(90)) - sinking to: Hfs["TextLine[['offset', 'line']->[ALL]]"]["/opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/test/output/hadoop2-mr1/cascadingstatslocalhadooperrorplatform/mapperfail"]
2014-08-22 21:26:02,065 ERROR stream.TrapHandler (TrapHandler.java:handleReThrowableException(103)) - caught Throwable, no trap available, rethrowing
cascading.CascadingException: testing
at cascading.stats.hadoop.CascadingStatsLocalHadoopErrorPlatformTest$FailFunction.operate(CascadingStatsLocalHadoopErrorPlatformTest.java:81)
at cascading.flow.stream.FunctionEachStage.receive(FunctionEachStage.java:99)
at cascading.flow.stream.FunctionEachStage.receive(FunctionEachStage.java:39)
at cascading.flow.stream.SourceStage.map(SourceStage.java:102)
at cascading.flow.stream.SourceStage.run(SourceStage.java:58)
at cascading.flow.hadoop.FlowMapper.run(FlowMapper.java:130)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:430)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:342)
at org.apache.hadoop.mapred.LocalJobRunner$Job$MapTaskRunnable.run(LocalJobRunner.java:243)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
at java.lang.Thread.run(Thread.java:662)
2014-08-22 21:26:02,066 ERROR stream.SourceStage (SourceStage.java:map(110)) - caught throwable
cascading.CascadingException: testing
at cascading.stats.hadoop.CascadingStatsLocalHadoopErrorPlatformTest$FailFunction.operate(CascadingStatsLocalHadoopErrorPlatformTest.java:81)
at cascading.flow.stream.FunctionEachStage.receive(FunctionEachStage.java:99)
at cascading.flow.stream.FunctionEachStage.receive(FunctionEachStage.java:39)
at cascading.flow.stream.SourceStage.map(SourceStage.java:102)
at cascading.flow.stream.SourceStage.run(SourceStage.java:58)
at cascading.flow.hadoop.FlowMapper.run(FlowMapper.java:130)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:430)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:342)
at org.apache.hadoop.mapred.LocalJobRunner$Job$MapTaskRunnable.run(LocalJobRunner.java:243)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
at java.lang.Thread.run(Thread.java:662)
2014-08-22 21:26:02,067 INFO mapred.LocalJobRunner (LocalJobRunner.java:runTasks(456)) - map task executor complete.
2014-08-22 21:26:02,069 WARN mapred.LocalJobRunner (LocalJobRunner.java:run(560)) - job_local65890607_0002
java.lang.Exception: cascading.CascadingException: testing
at org.apache.hadoop.mapred.LocalJobRunner$Job.runTasks(LocalJobRunner.java:462)
at org.apache.hadoop.mapred.LocalJobRunner$Job.run(LocalJobRunner.java:522)
Caused by: cascading.CascadingException: testing
at cascading.stats.hadoop.CascadingStatsLocalHadoopErrorPlatformTest$FailFunction.operate(CascadingStatsLocalHadoopErrorPlatformTest.java:81)
at cascading.flow.stream.FunctionEachStage.receive(FunctionEachStage.java:99)
at cascading.flow.stream.FunctionEachStage.receive(FunctionEachStage.java:39)
at cascading.flow.stream.SourceStage.map(SourceStage.java:102)
at cascading.flow.stream.SourceStage.run(SourceStage.java:58)
at cascading.flow.hadoop.FlowMapper.run(FlowMapper.java:130)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:430)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:342)
at org.apache.hadoop.mapred.LocalJobRunner$Job$MapTaskRunnable.run(LocalJobRunner.java:243)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
at java.lang.Thread.run(Thread.java:662)
2014-08-22 21:26:03,140 INFO mapred.LocalJobRunner (LocalJobRunner.java:statusUpdate(591)) - reduce > reduce
2014-08-22 21:26:07,031 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [mapper fail test] hadoop job job_local65890607_0002 state at FAILED
2014-08-22 21:26:07,032 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [mapper fail test] failure info: NA
2014-08-22 21:26:07,032 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [mapper fail test] task completion events identify failed tasks
2014-08-22 21:26:07,032 WARN flow.FlowStep (BaseFlowStep.java:logWarn(839)) - [mapper fail test] task completion events count: 0
2014-08-22 21:26:07,033 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [mapper fail test] stopping all jobs
2014-08-22 21:26:07,033 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [mapper fail test] stopping: (1/1) ...perrorplatform/mapperfail
2014-08-22 21:26:07,034 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [mapper fail test] stopped all jobs
2014-08-22 21:26:07,034 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [mapper fail test] shutting down job executor
2014-08-22 21:26:07,034 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [mapper fail test] shutdown complete
2014-08-22 21:26:07,035 INFO util.Hadoop18TapUtil (Hadoop18TapUtil.java:cleanTempPath(219)) - deleting temp path /opt/buildAgent-8.0.3/work/3945655b04626318/apache-2.3.x/build/test/output/hadoop2-mr1/cascadingstatslocalhadooperrorplatform/mapperfail/_temporary
2014-08-22 21:26:07,035 WARN cascade.Cascade (Cascade.java:logWarn(1001)) - [mapper fail test] flow failed: mapper fail test
cascading.flow.FlowException: local step failed
at cascading.flow.planner.FlowStepJob.blockOnJob(FlowStepJob.java:219)
at cascading.flow.planner.FlowStepJob.start(FlowStepJob.java:149)
at cascading.flow.planner.FlowStepJob.call(FlowStepJob.java:124)
at cascading.flow.planner.FlowStepJob.call(FlowStepJob.java:43)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
at java.lang.Thread.run(Thread.java:662)
Caused by: cascading.CascadingException: testing
at cascading.stats.hadoop.CascadingStatsLocalHadoopErrorPlatformTest$FailFunction.operate(CascadingStatsLocalHadoopErrorPlatformTest.java:81)
at cascading.flow.stream.FunctionEachStage.receive(FunctionEachStage.java:99)
at cascading.flow.stream.FunctionEachStage.receive(FunctionEachStage.java:39)
at cascading.flow.stream.SourceStage.map(SourceStage.java:102)
at cascading.flow.stream.SourceStage.run(SourceStage.java:58)
at cascading.flow.hadoop.FlowMapper.run(FlowMapper.java:130)
at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:430)
at org.apache.hadoop.mapred.MapTask.run(MapTask.java:342)
at org.apache.hadoop.mapred.LocalJobRunner$Job$MapTaskRunnable.run(LocalJobRunner.java:243)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:439)
... 5 more
2014-08-22 21:26:07,036 INFO cascade.Cascade (Cascade.java:logInfo(991)) - [mapper fail test] stopping all flows
2014-08-22 21:26:07,037 INFO cascade.Cascade (Cascade.java:logInfo(991)) - [mapper fail test] stopping flow: mapper fail test
2014-08-22 21:26:07,037 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [mapper fail test] stopping all jobs
2014-08-22 21:26:07,037 INFO flow.FlowStep (BaseFlowStep.java:logInfo(834)) - [mapper fail test] stopping: (1/1) ...perrorplatform/mapperfail
2014-08-22 21:26:07,037 INFO flow.Flow (BaseFlow.java:logInfo(1354)) - [mapper fail test] stopped all jobs
2014-08-22 21:26:07,037 INFO cascade.Cascade (Cascade.java:logInfo(991)) - [mapper fail test] stopped all flows